19 Commits
Author SHA1 Message Date
clawbot 71ee2aeda7 Log the start-up checkpoint's figures under their own names (closes #117)
check / check (push) Waiting to run
Initialize scanned the row of PRAGMA wal_checkpoint(TRUNCATE), which is
the busy flag, the frames in the WAL and the frames copied, into
wal_pages, checkpointed and moved; and a completed TRUNCATE reads 0 for
both counts. The line now logs busy, wal_frames and checkpointed_frames,
plus wal_bytes, the WAL file's size, which New reads before it opens the
database because the open writes a frame to the WAL. The line is a
warning when busy is 1. Tests open a database a second time while the
first stays open, with and without a read open on the first, and check
the line's level and figures.

Model: opus-5-5
2026-10-20 04:32:08 +02:00
clawbot 8d16bf9ea6 Add the Rationale section to README (closes #121)
check / check (push) Canceled after 0s
REPO_POLICIES.md requires a Rationale section saying why the program
exists. RIS Live sends only the changes to the routing table, so it
cannot answer which AS an address is routed to now; routewatch applies
the changes to its own tables and answers from them. The section says
those tables hold only the routes announced since routewatch first
started, and miss the updates it drops under load or while it is
stopped.

Model: opus-5-5
2026-10-20 04:24:41 +02:00
clawbot 651a9e22f6 Treat a path with AS 0 anywhere as a withdrawal (closes #141)
check / check (push) Canceled after 0s
An AS path that holds AS 0 anywhere, a member of an AS set included, now
decodes as an empty path. RFC 7607 makes such a path malformed and its
announcements withdrawals. An empty path already gets that handling:
the prefix handler deletes the peer's route for the prefix, and the AS
and peering handlers record nothing from it. Before, a path such as
[64496, 0, 64497] stored the route with origin AS64497, recorded both
ASes, and recorded the peerings between the path's other ASes.

Model: opus-5-5
2026-10-20 04:07:41 +02:00
clawbot 9280e2eb2c Keep the database files, logs and binaries out of the build context (closes #120)
check / check (push) Canceled after 0s
The daemon's database is db.sqlite with its -wal and -shm files, which
the .db patterns in .dockerignore and .gitignore did not match, so a
database left in the clone shipped in the image's source archive.
.dockerignore now also excludes the logs and the .exe, .dll, .so and
.dylib files .gitignore already ignores. A test opens a database and
checks that .dockerignore has an any-depth pattern for each of its
files.

Model: opus-5-5
2026-10-20 03:58:56 +02:00
clawbot 100689a4fb Keep prefixes that do not parse out of the prefix tables (closes #114)
check / check (push) Canceled after 0s
UpdatePrefixesBatch now skips a prefix that does not parse, so it never
becomes a row in prefixes_v4 or prefixes_v6 and never counts in the prefix
total in the stats. Before, the prefix handler stored no route for such a
prefix and logged it once per prefix and peer, but still passed it to
UpdatePrefixesBatch, which stored it.

Model: opus-5-5
2026-10-20 03:51:10 +02:00
clawbot e13240cb04 Show the MIT licence in the page footers (closes #119)
check / check (push) Canceled after 0s
version.License, which the home and status page footers show, still
said WTFPL after LICENSE and the README moved to MIT. It now says MIT.
A test renders both pages and expects each footer to name MIT and not
WTFPL.

Model: opus-5-5
2026-10-20 03:46:44 +02:00
clawbot 55ecb22846 Bound the WHOIS fetcher's success and error time lists (closes #118)
check / check (push) Canceled after 0s
recordSuccess and recordFailure appended a time on every fetch, and only
GetStats, run when a stats endpoint is requested, dropped the times older
than statsWindow, so a daemon nobody polled kept every one. Each now drops
those times before it appends. The drop takes them off the front of the
list instead of copying the rest: the times are in the order they were
recorded, and it now runs on every fetch.

The fetcher reads the time through a now field so a test can set the
clock. The test records 100,000 successes and failures a second apart
without asking for the stats and finds one hour's worth of each kept.

Model: opus-5-5
2026-10-20 03:38:51 +02:00
clawbot bae5a14d76 Reset the peering handler's dropped_paths figure after each log line (closes #116)
check / check (push) Canceled after 0s
processPeerings replaced the path map every run but kept the count of
paths dropped while the map was full, so every later "Processed AS
peerings" line reported all drops since start next to that run's own
figures. The count is now set to 0 where the map is replaced, under the
same lock. A test fills the map, has one path dropped, runs the
processing and finds the count back at 0.

Model: opus-5-5
2026-10-20 03:28:06 +02:00
clawbot 467c295f94 Handle an announcement without an origin like a replacement (closes #113)
check / check (push) Canceled after 0s
An announcement whose AS path is empty or ends in AS 0 now deletes the
peer's route for the prefix, as a withdrawal does. Before, it was neither
stored nor applied: the peer's old route stayed live, and within one
batch it cancelled the peer's earlier withdrawal of the prefix.

Model: opus-5-5
2026-10-20 03:25:41 +02:00
clawbot 2f238236bd Read the drop counter atomically and set the WHOIS fetcher before serving (closes #115)
check / check (push) Canceled after 0s
The read loop added to a handler's drop count atomically while the
statistics endpoint and the metrics log read it as a plain field, a data
race whenever messages were dropped. The count is now an atomic.Uint64,
read with Load. A test reads the handler statistics while the read loop
drops messages for a handler that never finishes one.

Run created the WHOIS fetcher and gave it to the HTTP server after the
server had started, while request handlers could read it. The fetcher is
now set before the server starts.

Model: opus-5-5
2026-10-20 03:18:00 +02:00
clawbot f489321e3a Answer HEAD requests and give 405 a plain message (closes #111)
check / check (push) Canceled after 0s
Every route was registered for GET only, so HEAD answered 405, and on
the JSON routes that 405 said "Internal server error". chi's GetHead
now serves HEAD with the GET handler; /ip and /ip/ register HEAD
themselves, as GetHead does not reach them. The /api/v1 and /ip route
groups answer a path they lack with a JSON 404 "Not found", and the
other methods the router knows (POST, PUT, PATCH, DELETE, OPTIONS,
TRACE, CONNECT) with a JSON 405 "Method not allowed" whose Allow header
names GET and HEAD. JSONValidationMiddleware gives a 4xx sent without a
JSON body the status's standard text instead of "Internal server error".

Model: opus-5-5
2026-10-20 03:06:23 +02:00
clawbot 444457bcf8 Store a new row's earliest timestamp as first_seen (closes #112)
check / check (push) Canceled after 0s
Each handler took the latest time per key in a batch and inserted it as
a new row's first_seen, so a key updated twice in one batch, seconds
apart, was stored first seen at the later time, and the IP lookup could
answer with a prefix first_seen after the route's last_seen.

The prefix handler now keeps the earliest time of all of the batch's
updates for each prefix. The AS, peer and peering handlers keep the
earliest and the latest time per key in database.SeenTimes, and
GetOrCreateASNBatch, UpdatePeerBatch and RecordPeering store a new row
first seen at the earliest and last seen at the latest. A stored row
still has only its last_seen set, to the latest.

Model: opus-5-5
2026-10-20 02:59:17 +02:00
clawbot c4dadd1477 Leave SIGINT and SIGTERM to fx (closes #131)
check / check (push) Canceled after 0s
The start hook registered its own handler for SIGINT and SIGTERM and
asked fx to shut down from it, although fx already stops the daemon on
both signals. A stop signal was handled twice, and the handler stayed
registered after the stop. fx now handles both signals alone, as
GO_HTTP_SERVER_CONVENTIONS.md "Signal Handling and Graceful Shutdown"
requires.

Model: opus-5-5
2026-10-20 02:34:04 +02:00
clawbot c7f2e5db1d Bound the IP lookup's address list and name lookups (closes #110)
check / check (push) Canceled after 0s
An IP lookup took any number of addresses and host names, gave each PTR
lookup until the request's 30-second limit, and looked up and named
every address a host name resolved to. It now answers 400 for more than
10 entries, or more than 10 addresses once the names are resolved,
before reading the database. Each PTR lookup gets 2 seconds; one that
runs out leaves the address's result without PTR names. Of a host
name's addresses only public ones are kept: global unicast and not
private. A name with none is reported as having no public address. The
tests give the server a fake resolver.

Model: opus-5-5
2026-10-20 02:23:49 +02:00
clawbot 09d3073fa5 Bound each shutdown stage by the stop deadline (closes #100)
check / check (push) Canceled after 0s
Shutdown passes its context to every stage: the streamer, the four
handlers, the WHOIS fetcher, the database maintainer and the HTTP server
each stop waiting when it ends. A handler then skips its last write and
logs how many updates it did not write, and the HTTP server closes the
connections still open. The database is checkpointed and closed last,
and left open once the deadline has passed, since a write may still
hold it. The stop hook gives Shutdown 8 seconds and fx 9, inside the 10
seconds upaas and docker stop allow, so a stop signal exits 0.

Model: opus-5-5
2026-10-20 02:15:10 +02:00
clawbot 237f73fc49 Answer 500, not 404, when the IP lookup cannot read the database (closes #109)
check / check (push) Canceled after 0s
A failed database read for an address was listed in the answer's errors
as if the address had no route, so the lookup answered 404, or 200 next
to a routed address. Only a missing route or an invalid address is
listed now; any other read error is logged and answers 500 with the JSON
error body, as the AS and prefix JSON routes do.

Model: opus-5-5
2026-10-20 01:49:34 +02:00
clawbot 89bdda18a5 Add the HTTP hardening the policy requires before 1.0 (closes #108)
check / check (push) Canceled after 0s
Every answer carries the six security headers REPO_POLICIES.md lists.
The Content-Security-Policy allows inline content only with a nonce made
for that answer; the pages put it on their style and script blocks and
drop their four style attributes.

The request log and /ip/ take a forwarded address only from a proxy
listed in TRUSTED_PROXIES, which stops the start when set but invalid:
the last X-Forwarded-For entry that is not a trusted proxy. X-Real-IP
and True-Client-IP are no longer read.

The JSON routes and the health check send fixed messages in place of
database, parser and resolver errors, and log the detail.

Model: opus-5-5
2026-10-20 01:36:18 +02:00
clawbot 76c2e523b5 Checkpoint without waiting on readers and log a busy checkpoint (closes #102)
check / check (push) Canceled after 0s
The 5-second checkpoint ran in TRUNCATE mode, which waits up to the
5-second busy timeout for every open read while holding the database
lock every batch write needs. It now runs in PASSIVE mode, which never
waits. A WAL file over 64 MiB instead gets one TRUNCATE checkpoint whose
wait for reads is capped at 500 ms and logged; it empties the file once
no read is open, and while reads follow one another with no pause it
can give up every time. A checkpoint that leaves part of the WAL
uncopied returns ErrCheckpointIncomplete, which the maintainer logs as
incomplete instead of completed. The writing connection's
journal_size_limit is 64 MiB.

Model: opus-5-5
2026-10-20 01:06:51 +02:00
clawbot 28f60500cb Read the AS page from bounded lookups (closes #104)
check / check (push) Canceled after 0s
The AS page and /api/v1/as/{asn} grouped every route the AS originates
by prefix, reading one table row per peer and prefix and sorting them
all. They now take the AS's prefixes one at a time: one search of a new
index on origin_asn and prefix, which replaces the origin_asn index and
is written exactly when it was, and one search of the prefix and
last_updated index for the time of the prefix's newest route. Neither
reads the table. For a prefix more than one AS originates, that time is
now the newest route's from any origin. A hand-run benchmark reads an
AS of 5,000 prefixes from 500 peers.

Model: opus-5-5
2026-10-20 00:52:32 +02:00
48 changed files with 4243 additions and 470 deletions
+12 -2
View File
@@ -73,7 +73,8 @@
# This repository's host-built artifacts: `make build` writes bin/, `go
# build` in the root the binaries, `make run` log.txt, `make asupdate` its
# .tmp file; test binaries, coverage profiles and source archives.
# .tmp file; logs, test binaries, coverage profiles, source archives, and
# the binaries and libraries a build for another platform writes.
/bin
/routewatch
/asinfo-gen
@@ -82,15 +83,24 @@
/out
/pkg/asinfo/asdata.json
**/*.tar.zst
**/*.log
**/*.test
**/*.out
**/*.tmp
**/*.exe
**/*.dll
**/*.so
**/*.dylib
# Local databases. The image carries a source archive of the whole build
# context, so these would otherwise ship inside it.
# context, so these would otherwise ship inside it. The daemon's database
# is db.sqlite, with its -wal and -shm files while it runs.
**/*.db
**/*.db-journal
**/*.db-wal
**/*.sqlite
**/*.sqlite-wal
**/*.sqlite-shm
# A local Go workspace points at directories outside the build context.
/go.work
+5 -1
View File
@@ -67,10 +67,14 @@ node_modules/
go.work
go.work.sum
# Local databases, temporary files and debug output.
# Local databases, temporary files and debug output. The daemon's
# database is db.sqlite, with its -wal and -shm files while it runs.
*.db
*.db-journal
*.db-wal
*.sqlite
*.sqlite-wal
*.sqlite-shm
*.tmp
log.txt
out
+86 -13
View File
@@ -5,6 +5,22 @@ table in real time: it streams BGP UPDATE messages from the RIPE RIS Live
service, maintains a live routing table in SQLite, and provides HTTP APIs for
querying routing information.
## Rationale
RIPE RIS Live streams the BGP updates that RIPE's route collectors receive, as
they happen, from the moment a client connects. It reports changes, not the
routing table they add up to, so it cannot say which AS an IP address is routed
to now or which routes a prefix has. RouteWatch applies the feed's updates to
live routing tables in its own SQLite database and answers IP-to-AS lookups and
prefix pages from them.
The feed sends no table when a client connects, so these tables hold only the
routes the feed has announced since RouteWatch first started: an IP-to-AS lookup
finds nothing for an address whose routes have not been announced since then.
The tables also miss the updates RouteWatch drops when it falls behind under
load and those sent while it is stopped, so a lookup or a prefix page can show a
route the feed has withdrawn.
## Features
- Real-time streaming of BGP updates from RIPE RIS Live
@@ -36,6 +52,8 @@ DEBUG=routewatch ./routewatch
## HTTP Endpoints
Every route answers `HEAD` as it answers `GET`, without the body.
### Web Interface
- `GET /` - Home page (HTML): headline figures, and lookups by AS number and by
@@ -54,8 +72,9 @@ DEBUG=routewatch ./routewatch
picked at random, each with its newest route (HTML)
- `GET /prefixlength6/{length}` - The same for IPv6
- `GET /ip/{addr}` - The same JSON answer as `/api/v1/ip/{ip}`
- `GET /ip/` - The same, for the caller's own address, or the one a proxy names
in `True-Client-IP`, `X-Real-IP` or `X-Forwarded-For`
- `GET /ip/` - The same, for the caller's own address: the address the request
came from or, when that is a trusted proxy (`TRUSTED_PROXIES`, see
Configuration), the client address in its `X-Forwarded-For`
### API v1
@@ -63,11 +82,16 @@ DEBUG=routewatch ./routewatch
collector, stream and handler queue statistics
- `GET /api/v1/ip/{ip}` - Looks up each address: its most specific live route
(`netblock`), that route's origin AS with its WHOIS details, and the address's
PTR names. `{ip}` is an IP address, a host name (each address it resolves to
is looked up), or a comma-separated list of these. `results` has one entry per
address with a live route and `errors` one per address or name that failed.
The answer is 400 when nothing in `{ip}` is an IP address or a host name that
resolves, and 404 when none of the addresses has a live route.
PTR names. `{ip}` is an IP address, a host name, or a comma-separated list of
at most 10 of these. Of the addresses a host name resolves to, only public
ones are looked up: a name with none, such as one that resolves to a private
address, is reported as `host name has no public address`, without its
addresses. `results` has one entry per address with a live route and `errors`
one per address or name that failed. The answer is 400 when `{ip}` lists more
than 10, when it comes to more than 10 addresses once its names are resolved,
or when nothing in it is an IP address or a host name with a public address;
and 404 when none of the addresses has a live route. A PTR lookup gets 2
seconds; an address whose lookup takes longer is answered without PTR names.
- `GET /api/v1/as/{asn}` - The AS and the prefixes it originates, IPv4 and IPv6
apart, each with when its newest route was updated
- `GET /api/v1/prefix/{prefix}/{length}` - Every live route for the prefix, one
@@ -84,7 +108,20 @@ and 4 seconds for the database reads behind `/status.json` and `/api/v1/stats`.
An AS number, prefix or mask length that does not parse answers 400, as does a
mask length out of range for its IP version. An AS the database does not hold,
or a prefix with no live route, answers 404. The HTML pages give these errors as
plain text.
plain text. Under `/api/v1` and `/ip/`, a path no route matches answers 404 with
the message `Not found`, and `POST`, `PUT`, `PATCH`, `DELETE`, `OPTIONS`,
`TRACE` or `CONNECT` answers 405 with `Method not allowed`. A 500 answer says
only `Internal server error`, and a host name that does not resolve only
`could not resolve host name`; the detail goes to the log.
Every answer carries `Strict-Transport-Security`, `Content-Security-Policy`,
`X-Frame-Options`, `X-Content-Type-Options`, `Referrer-Policy` and
`Permissions-Policy`. The Content-Security-Policy lets a page load content only
from the server, and does not allow inline content with `'unsafe-inline'`: the
pages keep their CSS and JavaScript in inline `<style>` and `<script>` blocks,
so each answer's policy names a random nonce made for that answer, and the
browser applies or runs only the blocks that carry it. The pages therefore use
no `style` attributes, which a nonce cannot cover.
An origin AS of 0 (`origin_asn` in a route, `asn` in an IP lookup, the key `0`
in a prefix's `origins`) means the route has no known origin: its AS path ends
@@ -174,7 +211,8 @@ routewatch/
- **ASHandler**: Tracks all ASNs seen in AS paths
- **PeerHandler**: Records BGP peer information
- **PrefixHandler**: Maintains live routing table (upserts on announcement,
deletes on withdrawal, deletes all of a peer's routes when its BGP session
deletes on withdrawal or on an announcement whose AS path is empty or
holds AS 0 anywhere, deletes all of a peer's routes when its BGP session
goes down). Routes are kept per peer IP, so when one peer IP has sessions
on two collectors, a session going down on one also removes the routes the
other still carries, until they are announced again.
@@ -191,7 +229,11 @@ routewatch/
batches for performance
- **Backpressure**: Probabilistic message dropping when queues exceed 50%
capacity
- **Graceful Shutdown**: 60-second timeout, flushes all pending batches
- **Graceful Shutdown**: on SIGTERM or SIGINT the streamer stops, the handlers
write the batches they hold, the HTTP server stops and the database is
checkpointed and closed. The daemon gives this 8 seconds and exits with status
0; "Running under upaas" says what a stop loses, logs and leaves undone when
the 8 seconds run out.
- **Reconnection**: Any end of the stream other than shutdown, including RIS
Live ending the response normally, marks the feed disconnected and reconnects
with exponential backoff (5s-320s). The backoff resets after a stream that
@@ -247,10 +289,20 @@ Configuration is handled via environment variables and OS-specific paths:
| `XDG_DATA_HOME` | `/var/lib` (in the Docker image) | Base of the state directory; must be an absolute path |
| `GOMEMLIMIT` | `1536MiB` (in the Docker image) | Go soft memory limit; see Memory |
| `MALLOC_ARENA_MAX` | `2` (in the Docker image) | glibc malloc arena cap, a positive whole number; see Memory |
| `TRUSTED_PROXIES` | (empty) | Addresses and CIDR ranges of trusted proxies; see below |
A variable that is set to an invalid value stops the start with an error and a
non-zero exit. An empty variable counts as unset.
`TRUSTED_PROXIES` lists the reverse proxies whose `X-Forwarded-For` the server
believes, comma-separated, such as `10.0.0.0/8,192.0.2.1`. For a request from
one of them, the request log and `/ip/` use the last address in
`X-Forwarded-For` that is not a trusted proxy: each proxy adds the address it
received the request from to the end, so the entries before it are whatever the
client sent. For a request from any other address they use the address the
request came from, whatever forwarding headers it carries. `X-Real-IP` and
`True-Client-IP` are not read.
State directory (database location):
- macOS: `~/Library/Application Support/berlin.sneak.app.routewatch/`
@@ -336,15 +388,36 @@ What the [upaas](https://git.eeqj.de/sneak/upaas) app needs:
- Container port: `8080`.
- Volume: one, at container path `/var/lib/berlin.sneak.app.routewatch`.
- Environment: nothing is required. Leave `XDG_DATA_HOME`, `GOMEMLIMIT` and
`MALLOC_ARENA_MAX` at the image's values. `DEBUG=routewatch` is optional and
adds the `System stats` memory line to the log.
- Environment: `TRUSTED_PROXIES`, set to the address the reverse proxy in front
of the app connects from, as the container sees it; without it the request log
and `/ip/` give the proxy's address for every request. Nothing else is needed:
leave `XDG_DATA_HOME`, `GOMEMLIMIT` and `MALLOC_ARENA_MAX` at the image's
values. `DEBUG=routewatch` is optional and adds the `System stats` memory line
to the log.
- Memory Limit: `5g`, the 5 GiB limit from Memory above. upaas sets no swap
limit, so on a host with swap Docker allows the same amount of swap again.
- Health check: the image's `HEALTHCHECK` requests
`/.well-known/healthcheck.json` on the container port. upaas reads the
container's health 60 seconds after a deploy and fails the deploy unless it is
`healthy`.
- Stop grace: the container needs 9 seconds between SIGTERM and SIGKILL. upaas
gives 10 (`stopTimeoutSeconds` in its `internal/docker/client.go`), as
`docker stop` does by default. The daemon allows 8 seconds for the handlers to
write what they hold and for the requests in progress to finish, then stops
the HTTP server, closes the database and exits with status 0. A longer grace
changes nothing. What is not written after 8 seconds is lost, and the streamer
and each handler log how much. When the prefix handler has fallen behind the
feed, a stop loses far more: its batch is full at 250,000 updates and the
streamer's worker for it waits for room, so the streamer's stop takes the
whole 8 seconds and every handler then skips its last write. Lost then are the
messages left on the four handlers' queues, what the AS, peer and peering
handlers hold, the prefix handler's batch, and the write it has in progress,
up to another 250,000 updates, which take about 20 seconds and are cut off by
the exit; withdrawals and peer downs are among them. A route withdrawn in them
stays in the live route table until its peer announces or withdraws the prefix
again or its session goes down. When the 8 seconds run out the database is not
closed, and SQLite rolls back a write the exit cut off when the database next
opens.
## Development
+1 -1
View File
@@ -35,7 +35,7 @@ func main() {
if err != nil {
log.Fatal("Failed to start streamer:", err)
}
defer s.Stop()
defer s.Stop(context.Background())
// Set up context with cancellation
ctx, cancel := context.WithCancel(context.Background())
+48 -2
View File
@@ -4,10 +4,12 @@ package config
import (
"errors"
"fmt"
"net/netip"
"os"
"path/filepath"
"runtime"
"strconv"
"strings"
"time"
)
@@ -32,6 +34,8 @@ var (
errRelativeXDGDataHome = errors.New("XDG_DATA_HOME must be an absolute path")
errUnsupportedOS = errors.New("unsupported operating system")
errInvalidPort = errors.New("PORT must be a whole number")
errInvalidProxy = errors.New(
"TRUSTED_PROXIES must list IP addresses and CIDR ranges, comma-separated")
)
// Config holds configuration for the entire application
@@ -42,6 +46,10 @@ type Config struct {
// Port is the TCP port the HTTP server listens on
Port int
// TrustedProxies are the reverse proxies whose X-Forwarded-For header
// the HTTP server believes
TrustedProxies []netip.Prefix
// MaxRuntime is the maximum runtime (0 = run forever)
MaxRuntime time.Duration
@@ -68,9 +76,15 @@ func New() (*Config, error) {
return nil, err
}
trustedProxies, err := getTrustedProxies()
if err != nil {
return nil, err
}
return &Config{
StateDir: stateDir,
Port: port,
StateDir: stateDir,
Port: port,
TrustedProxies: trustedProxies,
// Run forever by default
MaxRuntime: 0,
// Enable batching by default
@@ -145,6 +159,38 @@ func getPort() (int, error) {
return int(port), nil
}
// getTrustedProxies returns the addresses and CIDR ranges listed in
// TRUSTED_PROXIES, such as "10.0.0.0/8,192.0.2.1", or none when it is not set.
// An address is returned as a range holding only that address.
func getTrustedProxies() ([]netip.Prefix, error) {
value := os.Getenv("TRUSTED_PROXIES")
if value == "" {
return nil, nil
}
var proxies []netip.Prefix
for entry := range strings.SplitSeq(value, ",") {
entry = strings.TrimSpace(entry)
addr, err := netip.ParseAddr(entry)
if err == nil {
proxies = append(proxies, netip.PrefixFrom(addr, addr.BitLen()))
continue
}
prefix, err := netip.ParsePrefix(entry)
if err != nil {
return nil, fmt.Errorf("%w, got %q", errInvalidProxy, entry)
}
proxies = append(proxies, prefix)
}
return proxies, nil
}
// EnsureDirectories creates all necessary directories if they don't exist
func (c *Config) EnsureDirectories() error {
// Ensure state directory exists
+51
View File
@@ -1,7 +1,9 @@
package config
import (
"net/netip"
"runtime"
"slices"
"testing"
)
@@ -44,6 +46,55 @@ func TestNewRefusesInvalidPort(t *testing.T) {
}
}
func TestNewReadsTrustedProxies(t *testing.T) {
t.Setenv("PORT", "")
t.Setenv("XDG_DATA_HOME", "")
t.Setenv("TRUSTED_PROXIES", "")
cfg, err := New()
if err != nil {
t.Fatalf("New() without TRUSTED_PROXIES: %v", err)
}
if len(cfg.TrustedProxies) != 0 {
t.Errorf("New() without TRUSTED_PROXIES: TrustedProxies = %v, want none",
cfg.TrustedProxies)
}
t.Setenv("TRUSTED_PROXIES", "10.0.0.0/8, 192.0.2.1,2001:db8::/32")
cfg, err = New()
if err != nil {
t.Fatalf("New() with TRUSTED_PROXIES: %v", err)
}
want := []netip.Prefix{
netip.MustParsePrefix("10.0.0.0/8"),
netip.MustParsePrefix("192.0.2.1/32"),
netip.MustParsePrefix("2001:db8::/32"),
}
if !slices.Equal(cfg.TrustedProxies, want) {
t.Errorf("TrustedProxies = %v, want %v", cfg.TrustedProxies, want)
}
}
func TestNewRefusesInvalidTrustedProxies(t *testing.T) {
invalid := []string{"proxy.example", "10.0.0.0/33", "192.0.2.1:80", "192.0.2.1,"}
for _, value := range invalid {
t.Run(value, func(t *testing.T) {
t.Setenv("PORT", "")
t.Setenv("XDG_DATA_HOME", "")
t.Setenv("TRUSTED_PROXIES", value)
_, err := New()
if err == nil {
t.Errorf("New() with TRUSTED_PROXIES=%q returned no error", value)
}
})
}
}
func TestNewRefusesRelativeXDGDataHome(t *testing.T) {
if runtime.GOOS == "darwin" {
t.Skip("macOS does not read XDG_DATA_HOME")
+9 -4
View File
@@ -148,7 +148,9 @@ func TestLiveCountsTrackWritesInRealtime(t *testing.T) {
func writeASNsPrefixesAndPeers(t *testing.T, db *Database, ts time.Time) {
t.Helper()
err := db.GetOrCreateASNBatch(map[int]time.Time{64500: ts, 64501: ts})
seen := SeenTimes{First: ts, Last: ts}
err := db.GetOrCreateASNBatch(map[int]SeenTimes{64500: seen, 64501: seen})
if err != nil {
t.Fatalf("GetOrCreateASNBatch: %v", err)
}
@@ -164,14 +166,14 @@ func writeASNsPrefixesAndPeers(t *testing.T, db *Database, ts time.Time) {
err = db.UpdatePeerBatch(map[string]PeerUpdate{
testV4PeerIP: {
PeerIP: testV4PeerIP, PeerASN: 64500,
MessageType: "UPDATE", Timestamp: ts,
MessageType: "UPDATE", Seen: seen,
},
})
if err != nil {
t.Fatalf("UpdatePeerBatch: %v", err)
}
err = db.RecordPeering(64500, 64501, ts)
err = db.RecordPeering(64500, 64501, seen)
if err != nil {
t.Fatalf("RecordPeering: %v", err)
}
@@ -192,7 +194,10 @@ func TestLiveCountsSeededFromDatabaseAtStartup(t *testing.T) {
ts := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
err = db.GetOrCreateASNBatch(map[int]time.Time{64500: ts, 64501: ts, 64502: ts})
seen := SeenTimes{First: ts, Last: ts}
err = db.GetOrCreateASNBatch(
map[int]SeenTimes{64500: seen, 64501: seen, 64502: seen})
if err != nil {
t.Fatalf("GetOrCreateASNBatch: %v", err)
}
+251 -92
View File
@@ -81,6 +81,23 @@ const (
sqliteHardHeapLimitBytes = 2147483648
)
// Settings that bound the WAL file's size once no read is open (see
// Checkpoint).
const (
// sqliteWALSizeLimitBytes (64 MiB) is the WAL file size past which
// Checkpoint runs a TRUNCATE checkpoint. It is also the
// journal_size_limit of the connection kept for writing: when SQLite
// starts the WAL again from the beginning, it cuts a larger WAL file down
// to this size.
sqliteWALSizeLimitBytes = 67108864
// truncateBusyTimeoutMs is the busy timeout of the TRUNCATE checkpoint:
// the longest it waits for open reads, and so the longest it keeps batch
// writes waiting beyond the copy itself.
truncateBusyTimeoutMs = 500
// walFileSuffix ends the name of the WAL file, next to the database file.
walFileSuffix = "-wal"
)
// Settings of the ANALYZE that Analyze runs.
const (
// analysisLimit is about how many rows of each index ANALYZE reads
@@ -112,6 +129,12 @@ var (
ErrNoRoute = errors.New("no route found")
// ErrNoStaleASN is returned when no ASN needs WHOIS refresh
ErrNoStaleASN = errors.New("no stale ASN found")
// ErrCheckpointIncomplete is returned by Checkpoint when it left part of
// the WAL uncopied, or left a WAL file over sqliteWALSizeLimitBytes
// untruncated, because reads still needed the WAL or SQLite reported the
// checkpoint busy. A later checkpoint that runs when no read is open
// finishes the work.
ErrCheckpointIncomplete = errors.New("WAL checkpoint incomplete")
errInvalidASN = errors.New("invalid ASN")
errSameASNInPeering = errors.New("cannot create peering with same ASN")
@@ -146,6 +169,20 @@ func New(cfg *config.Config, logger *logger.Logger) (*Database, error) {
return nil, fmt.Errorf("failed to create database directory: %w", err)
}
// The size of the WAL file the previous run left, which Initialize logs
// with the start-up checkpoint. It is read before the database is opened,
// because opening it writes a frame to the WAL. There is no WAL file when
// the database is new or the last run closed the database, which deletes
// it.
var walBytes int64
wal, err := os.Stat(dbPath + walFileSuffix)
if err == nil {
walBytes = wal.Size()
} else if !errors.Is(err, os.ErrNotExist) {
logger.Warn("Failed to read the WAL file's size on startup", "error", err)
}
// Per-connection SQLite settings go in the DSN so every pooled connection
// gets them, not just the one that runs the Initialize pragmas. _txlock=
// immediate makes every transaction take the write lock at BEGIN. Without it
@@ -194,12 +231,19 @@ func New(cfg *config.Config, logger *logger.Logger) (*Database, error) {
err)
}
_, err = writer.ExecContext(ctx,
fmt.Sprintf("PRAGMA journal_size_limit=%d", sqliteWALSizeLimitBytes))
if err != nil {
return nil, fmt.Errorf(
"failed to set the writing connection's WAL size limit: %w", err)
}
database := &Database{
db: db, writer: writer, logger: logger, path: dbPath,
counts: &liveCounts{},
}
err = database.Initialize()
err = database.Initialize(walBytes)
if err != nil {
return nil, fmt.Errorf("failed to initialize database: %w", err)
}
@@ -215,8 +259,16 @@ func New(cfg *config.Config, logger *logger.Logger) (*Database, error) {
return database, nil
}
// Initialize creates the database schema if it doesn't exist.
func (d *Database) Initialize() error {
// The messages Initialize logs the start-up WAL checkpoint with.
const (
startupCheckpointMessage = "WAL checkpoint on startup"
startupCheckpointIncompleteMessage = "WAL checkpoint on startup incomplete"
)
// Initialize creates the database schema if it doesn't exist. walBytes is the
// size of the WAL file the previous run left, which New reads before it opens
// the database.
func (d *Database) Initialize(walBytes int64) error {
// Set SQLite pragmas for performance. Per-connection settings (cache_size,
// synchronous, busy_timeout, journal_mode) live in the DSN, and New sets the
// writing connection's cache_size; temp_store is left at its default so
@@ -236,19 +288,33 @@ func (d *Database) Initialize() error {
}
}
// Run WAL checkpoint on startup to consolidate any existing WAL
var walPages, checkpointedPages, movedPages int
// The start-up checkpoint copies the WAL a previous run left into the
// database file and empties the WAL file; its frame counts then read 0,
// so walBytes is logged with them.
var busy, walFrames, checkpointedFrames int
err := d.writer.QueryRowContext(context.Background(),
"PRAGMA wal_checkpoint(TRUNCATE)",
).Scan(&walPages, &checkpointedPages, &movedPages)
if err != nil {
).Scan(&busy, &walFrames, &checkpointedFrames)
switch {
case err != nil:
d.logger.Warn("Failed to checkpoint WAL on startup", "error", err)
} else {
d.logger.Info("WAL checkpoint on startup",
"wal_pages", walPages,
"checkpointed", checkpointedPages,
"moved", movedPages,
case busy != 0:
// Another process using the database kept the checkpoint from
// copying or emptying all of the WAL.
d.logger.Warn(startupCheckpointIncompleteMessage,
"wal_bytes", walBytes,
"busy", busy,
"wal_frames", walFrames,
"checkpointed_frames", checkpointedFrames,
)
default:
d.logger.Info(startupCheckpointMessage,
"wal_bytes", walBytes,
"busy", busy,
"wal_frames", walFrames,
"checkpointed_frames", checkpointedFrames,
)
}
@@ -825,7 +891,7 @@ func insertPrefixesInTable(
// UpdatePrefixesBatch stores, in a single transaction, the prefixes that are
// not stored yet, each first seen at its time in prefixes: the IPv4 prefixes
// first and then the IPv6 prefixes.
// first and then the IPv6 prefixes. A prefix that does not parse is not stored.
func (d *Database) UpdatePrefixesBatch(prefixes map[string]time.Time) error {
if len(prefixes) == 0 {
return nil
@@ -844,6 +910,11 @@ func (d *Database) UpdatePrefixesBatch(prefixes map[string]time.Time) error {
prefixesV6 := make(map[string]time.Time)
for prefix, timestamp := range prefixes {
_, err := netip.ParsePrefix(prefix)
if err != nil {
continue
}
if detectIPVersion(prefix) == ipVersionV4 {
prefixesV4[prefix] = timestamp
} else {
@@ -873,13 +944,14 @@ func (d *Database) UpdatePrefixesBatch(prefixes map[string]time.Time) error {
return nil
}
// newASN returns a new ASN record first and last seen at timestamp, with the
// handle and description from the AS info lookup when it knows the number.
func newASN(number int, timestamp time.Time) ASN {
// newASN returns a new ASN record first seen at seen.First and last seen at
// seen.Last, with the handle and description from the AS info lookup when it
// knows the number.
func newASN(number int, seen SeenTimes) ASN {
asn := ASN{
ASN: number,
FirstSeen: timestamp,
LastSeen: timestamp,
FirstSeen: seen.First,
LastSeen: seen.Last,
}
// Look up ASN info
@@ -891,12 +963,12 @@ func newASN(number int, timestamp time.Time) ASN {
return asn
}
// upsertASN updates the last_seen time of ASN number with the given
// upsertASN sets the last_seen time of ASN number to seen.Last with the given
// statements, inserting the ASN when it is new. It reports whether it inserted
// it.
func upsertASN(
ctx context.Context, selectStmt, updateStmt, insertStmt *sql.Stmt,
number int, timestamp time.Time,
number int, seen SeenTimes,
) (bool, error) {
var (
asn ASN
@@ -907,7 +979,7 @@ func upsertASN(
&description, &asn.FirstSeen, &asn.LastSeen)
if err == nil {
// ASN exists, update last_seen
_, err = updateStmt.ExecContext(ctx, timestamp, number)
_, err = updateStmt.ExecContext(ctx, seen.Last, number)
if err != nil {
return false, fmt.Errorf("failed to update ASN %d: %w", number, err)
}
@@ -920,7 +992,7 @@ func upsertASN(
}
// ASN doesn't exist, create it
asn = newASN(number, timestamp)
asn = newASN(number, seen)
_, err = insertStmt.ExecContext(ctx, asn.ASN, asn.Handle,
asn.Description, asn.FirstSeen, asn.LastSeen)
@@ -932,7 +1004,7 @@ func upsertASN(
}
// GetOrCreateASNBatch creates or updates multiple ASNs in a single transaction
func (d *Database) GetOrCreateASNBatch(asns map[int]time.Time) error {
func (d *Database) GetOrCreateASNBatch(asns map[int]SeenTimes) error {
if len(asns) == 0 {
return nil
}
@@ -974,9 +1046,9 @@ func (d *Database) GetOrCreateASNBatch(asns map[int]time.Time) error {
var newASNs int
for number, timestamp := range asns {
for number, seen := range asns {
inserted, err := upsertASN(ctx, selectStmt, updateStmt, insertStmt,
number, timestamp)
number, seen)
if err != nil {
return err
}
@@ -1045,7 +1117,7 @@ func (d *Database) GetOrCreateASN(number int, timestamp time.Time) (*ASN, error)
}
// ASN doesn't exist, create it with ASN info lookup
asn = newASN(number, timestamp)
asn = newASN(number, SeenTimes{First: timestamp, Last: timestamp})
_, err = tx.Exec("INSERT INTO asns "+
"(asn, handle, description, first_seen, last_seen) "+
@@ -1152,7 +1224,7 @@ func (d *Database) RecordAnnouncement(announcement *Announcement) error {
}
// RecordPeering records a peering relationship between two ASNs.
func (d *Database) RecordPeering(asA, asB int, timestamp time.Time) error {
func (d *Database) RecordPeering(asA, asB int, seen SeenTimes) error {
// Validate ASNs
if asA <= 0 || asB <= 0 {
return fmt.Errorf("%w: asA=%d, asB=%d", errInvalidASN, asA, asB)
@@ -1188,12 +1260,12 @@ func (d *Database) RecordPeering(asA, asB int, timestamp time.Time) error {
if exists {
_, err = tx.Exec(
"UPDATE peerings SET last_seen = ? WHERE as_a = ? AND as_b = ?",
timestamp, asA, asB)
seen.Last, asA, asB)
} else {
_, err = tx.Exec(`
INSERT INTO peerings (id, as_a, as_b, first_seen, last_seen)
VALUES (?, ?, ?, ?, ?)`,
generateUUID().String(), asA, asB, timestamp, timestamp)
generateUUID().String(), asA, asB, seen.First, seen.Last)
}
if err != nil {
@@ -1271,11 +1343,11 @@ func (d *Database) UpdatePeerBatch(peers map[string]PeerUpdate) error {
if exists {
_, err = updateStmt.ExecContext(ctx, update.PeerASN,
update.Timestamp, update.MessageType, update.PeerIP)
update.Seen.Last, update.MessageType, update.PeerIP)
} else {
_, err = insertStmt.ExecContext(ctx,
generateUUID().String(), update.PeerIP, update.PeerASN,
update.Timestamp, update.Timestamp, update.MessageType)
update.Seen.First, update.Seen.Last, update.MessageType)
}
if err != nil {
@@ -1673,8 +1745,9 @@ func (d *Database) GetASDetails(asn int) (*ASN, []LiveRoute, error) {
return d.GetASDetailsContext(context.Background(), asn)
}
// GetASDetailsContext returns detailed information about an AS including
// prefixes with context support
// GetASDetailsContext returns the AS and the prefixes it originates, the IPv4
// ones first, each once with the time of its newest route. It makes two index
// searches per prefix, however many peers carry the prefix.
func (d *Database) GetASDetailsContext(
ctx context.Context, asn int,
) (*ASN, []LiveRoute, error) {
@@ -1701,27 +1774,12 @@ func (d *Database) GetASDetailsContext(
asnInfo.Handle = handle.String
asnInfo.Description = description.String
// Get prefixes announced by this AS from both tables
queryV4 := `
SELECT prefix, mask_length, MAX(last_updated) as last_updated
FROM live_routes_v4
WHERE origin_asn = ?
GROUP BY prefix, mask_length
`
allPrefixes, err := d.originPrefixes(ctx, queryV4, asn, ipVersionV4)
allPrefixes, err := d.originPrefixes(ctx, asn, ipVersionV4)
if err != nil {
return &asnInfo, nil, err
}
queryV6 := `
SELECT prefix, mask_length, MAX(last_updated) as last_updated
FROM live_routes_v6
WHERE origin_asn = ?
GROUP BY prefix, mask_length
`
prefixesV6, err := d.originPrefixes(ctx, queryV6, asn, ipVersionV6)
prefixesV6, err := d.originPrefixes(ctx, asn, ipVersionV6)
if err != nil {
return &asnInfo, allPrefixes, err
}
@@ -2255,9 +2313,24 @@ func (d *Database) Analyze(ctx context.Context) error {
return nil
}
// Checkpoint runs a WAL checkpoint to transfer data from the WAL to the main database.
// Uses TRUNCATE mode which blocks writers briefly but ensures complete checkpoint,
// keeping the WAL small for fast read performance. It holds the database lock.
// Checkpoint copies the WAL into the database file. It holds the database
// lock, so batch writes wait while it runs.
//
// It runs a PASSIVE checkpoint, which never waits: it copies what no open read
// still needs, and leaves the file as large as it is. When the file is over
// sqliteWALSizeLimitBytes, Checkpoint runs one TRUNCATE checkpoint instead,
// which waits at most truncateBusyTimeoutMs for the open reads to end, then
// copies all of the WAL and empties the file, or gives up. It is logged with
// how long it took and whether it emptied the file.
//
// So a file over the limit is emptied by the first Checkpoint that finds no
// read open, at its start or at some moment of its wait. While reads follow
// one another with no pause between them, every TRUNCATE checkpoint can give
// up after its full wait, and the file can keep growing for as long as they
// do.
//
// It returns ErrCheckpointIncomplete when it leaves part of the WAL uncopied,
// or a file over the limit not emptied.
func (d *Database) Checkpoint(ctx context.Context) error {
d.lock("Checkpoint")
defer d.unlock()
@@ -2267,11 +2340,32 @@ func (d *Database) Checkpoint(ctx context.Context) error {
return fmt.Errorf("failed to checkpoint WAL: %w", err)
}
_, err = d.writer.ExecContext(ctx, "PRAGMA wal_checkpoint(TRUNCATE)")
wal, err := os.Stat(d.path + walFileSuffix)
if err != nil {
return fmt.Errorf("failed to read the WAL file's size: %w", err)
}
if wal.Size() > sqliteWALSizeLimitBytes {
return d.truncateWAL(ctx, wal.Size())
}
var busy, walPages, copiedPages int
err = d.writer.QueryRowContext(ctx, "PRAGMA wal_checkpoint(PASSIVE)").
Scan(&busy, &walPages, &copiedPages)
if err != nil {
return fmt.Errorf("failed to checkpoint WAL: %w", err)
}
if busy != 0 {
return fmt.Errorf("%w: SQLite reported it busy", ErrCheckpointIncomplete)
}
if copiedPages < walPages {
return fmt.Errorf("%w: copied %d of %d WAL pages",
ErrCheckpointIncomplete, copiedPages, walPages)
}
return nil
}
@@ -2287,6 +2381,50 @@ func (d *Database) Ping(ctx context.Context) error {
return nil
}
// truncateWAL runs the TRUNCATE checkpoint of Checkpoint on a WAL file of
// walBytes, with the writing connection's busy timeout lowered to
// truncateBusyTimeoutMs for it, and logs how long it took. The caller holds the
// database lock.
func (d *Database) truncateWAL(ctx context.Context, walBytes int64) error {
_, err := d.writer.ExecContext(ctx,
fmt.Sprintf("PRAGMA busy_timeout=%d", truncateBusyTimeoutMs))
if err != nil {
return fmt.Errorf("failed to lower the busy timeout to truncate WAL: %w",
err)
}
started := time.Now()
var busy, walPages, copiedPages int
checkpointErr := d.writer.QueryRowContext(ctx,
"PRAGMA wal_checkpoint(TRUNCATE)").Scan(&busy, &walPages, &copiedPages)
took := time.Since(started)
// Restored even when ctx has ended, so that no batch write runs with the
// short timeout.
_, restoreErr := d.writer.ExecContext(context.WithoutCancel(ctx),
fmt.Sprintf("PRAGMA busy_timeout=%d", sqliteBusyTimeoutMs))
if checkpointErr != nil || restoreErr != nil {
return fmt.Errorf("failed to truncate WAL: %w",
errors.Join(checkpointErr, restoreErr))
}
if busy != 0 {
d.logger.Warn("WAL file over its size limit not truncated",
"wal_bytes", walBytes, "wal_pages", walPages,
"copied_pages", copiedPages, "duration", took)
return fmt.Errorf("%w: WAL file of %d bytes not truncated",
ErrCheckpointIncomplete, walBytes)
}
d.logger.Info("WAL file over its size limit truncated",
"wal_bytes", walBytes, "duration", took)
return nil
}
// The debug messages lock logs, with the operation's name, when it starts to
// wait for the database mutex and when it holds it.
const (
@@ -2452,66 +2590,87 @@ func (d *Database) scanRouteTimestamp(
}
}
// originPrefixes runs query, which selects the prefix, mask length and latest
// last_updated of every prefix asn originates in the live route table of
// ipVersion. Rows that fail to scan or whose timestamp does not parse are
// logged and skipped.
// The AS page lists the prefixes an AS originates one at a time, each in two
// index searches that read no table row: one of the origin_asn and prefix
// index for the AS's first prefix after the previous one, and one of the
// prefix and last_updated index for the time of its newest route. Neither
// reads more for a prefix that more peers carry.
const (
nextOriginPrefixV4SQL = `SELECT prefix FROM live_routes_v4
WHERE origin_asn = ? AND prefix > ? ORDER BY prefix LIMIT 1`
newestRouteTimeV4SQL = `SELECT last_updated FROM live_routes_v4
WHERE prefix = ? ORDER BY last_updated DESC LIMIT 1`
nextOriginPrefixV6SQL = `SELECT prefix FROM live_routes_v6
WHERE origin_asn = ? AND prefix > ? ORDER BY prefix LIMIT 1`
newestRouteTimeV6SQL = `SELECT last_updated FROM live_routes_v6
WHERE prefix = ? ORDER BY last_updated DESC LIMIT 1`
)
// originPrefixes returns every prefix asn originates in the live route table
// of ipVersion, in text order, each with its mask length and the time of the
// prefix's newest route, whichever AS that route names as origin. A prefix
// whose routes were all withdrawn between the two searches is left out.
func (d *Database) originPrefixes(
ctx context.Context, query string, asn, ipVersion int,
ctx context.Context, asn, ipVersion int,
) ([]LiveRoute, error) {
family := ipv4Family
family, nextSQL, newestSQL := ipv4Family, nextOriginPrefixV4SQL,
newestRouteTimeV4SQL
if ipVersion == ipVersionV6 {
family = ipv6Family
family, nextSQL, newestSQL = ipv6Family, nextOriginPrefixV6SQL,
newestRouteTimeV6SQL
}
rows, err := d.db.QueryContext(ctx, query, asn)
nextStmt, err := d.db.PrepareContext(ctx, nextSQL)
if err != nil {
return nil, fmt.Errorf("failed to query %s prefixes: %w", family, err)
return nil, fmt.Errorf("failed to prepare %s prefix query: %w",
family, err)
}
defer func() { _ = rows.Close() }()
defer func() { _ = nextStmt.Close() }()
newestStmt, err := d.db.PrepareContext(ctx, newestSQL)
if err != nil {
return nil, fmt.Errorf("failed to prepare %s route time query: %w",
family, err)
}
defer func() { _ = newestStmt.Close() }()
var routes []LiveRoute
for rows.Next() {
var (
route LiveRoute
lastUpdatedStr string
)
previous := "" // every prefix sorts after the empty string
for {
var prefix string
err := nextStmt.QueryRowContext(ctx, asn, previous).Scan(&prefix)
if errors.Is(err, sql.ErrNoRows) {
return routes, nil
}
err := rows.Scan(&route.Prefix, &route.MaskLength, &lastUpdatedStr)
if err != nil {
d.logger.Error("Failed to scan "+family+" prefix row",
"error", err, "asn", asn)
return nil, fmt.Errorf("failed to list %s prefixes: %w", family, err)
}
previous = prefix
route := LiveRoute{Prefix: prefix, IPVersion: ipVersion, OriginASN: asn}
err = newestStmt.QueryRowContext(ctx, prefix).Scan(&route.LastUpdated)
if errors.Is(err, sql.ErrNoRows) {
continue
}
// Parse the timestamp string
route.LastUpdated, err = time.Parse("2006-01-02 15:04:05-07:00",
lastUpdatedStr)
if err != nil {
// Try without timezone
route.LastUpdated, err = time.Parse("2006-01-02 15:04:05",
lastUpdatedStr)
if err != nil {
d.logger.Error("Failed to parse timestamp",
"error", err, "timestamp", lastUpdatedStr)
return nil, fmt.Errorf("failed to query route time of %s: %w",
prefix, err)
}
continue
}
route.MaskLength, err = prefixMaskLength(prefix)
if err != nil {
return nil, err
}
route.OriginASN = asn
route.IPVersion = ipVersion
routes = append(routes, route)
}
err = rows.Err()
if err != nil {
return nil, fmt.Errorf("failed to read %s prefixes: %w", family, err)
}
return routes, nil
}
// firstPrefixesByLength returns the first n prefixes, in text order, with the
+666 -4
View File
@@ -1,15 +1,19 @@
package database
import (
"bytes"
"context"
"database/sql"
"encoding/json"
"errors"
"fmt"
"log/slog"
"math/rand/v2"
"net/netip"
"os"
"slices"
"strconv"
"strings"
"sync"
"testing"
"time"
@@ -67,6 +71,15 @@ const (
lockWaitTimeout = time.Millisecond
// lockTestASN is the AS the batch write in the lock tests stores.
lockTestASN = 64500
// readerCheckpointLimit is how long a checkpoint, and a batch write
// waiting for it, may take while a reader is open: well under the busy
// timeout, which a checkpoint that waits for the reader takes.
readerCheckpointLimit = time.Second
// truncateCheckpointLimit is how long a checkpoint of a WAL file over
// sqliteWALSizeLimitBytes may take to give up while a reader is open: its
// wait for the reader plus a second, well under the busy timeout.
truncateCheckpointLimit = truncateBusyTimeoutMs*time.Millisecond +
time.Second
)
// Parameters for the prefix-length sample tests.
@@ -457,6 +470,33 @@ func TestWritingConnectionCache(t *testing.T) {
}
}
// TestWritingConnectionWALSizeLimit checks that the connection kept for
// writing, the one that writes the WAL, has the WAL size limit, which cuts the
// WAL file back when SQLite starts the WAL again from the beginning.
func TestWritingConnectionWALSizeLimit(t *testing.T) {
t.Parallel()
db, err := New(&config.Config{StateDir: t.TempDir()}, logger.New())
if err != nil {
t.Fatalf("failed to create database: %v", err)
}
defer func() { _ = db.Close() }()
var limit int64
err = db.writer.QueryRowContext(t.Context(), "PRAGMA journal_size_limit").
Scan(&limit)
if err != nil {
t.Fatalf("failed to read the writing connection's journal_size_limit: %v",
err)
}
if limit != sqliteWALSizeLimitBytes {
t.Errorf("writing connection: journal_size_limit = %d, want %d",
limit, sqliteWALSizeLimitBytes)
}
}
// readPragma reads the integer value of PRAGMA name on connection i, c.
func readPragma(
ctx context.Context, t *testing.T, c *sql.Conn, i int, name string,
@@ -577,10 +617,12 @@ func TestBatchWriteDuringCheckpoint(t *testing.T) {
})
ts := time.Now().UTC()
seen := SeenTimes{First: ts, Last: ts}
for i := range contentionIterations {
asns := map[int]time.Time{
i % contendedASNCount: ts,
(i % contendedASNCount) + asnSecondBand: ts,
asns := map[int]SeenTimes{
i % contendedASNCount: seen,
(i % contendedASNCount) + asnSecondBand: seen,
}
err := db.GetOrCreateASNBatch(asns)
@@ -709,7 +751,8 @@ func TestBatchWriteWaitsForAnalyze(t *testing.T) {
db, messages := newDatabaseWithLockMessages(t)
ctx := context.Background()
asns := map[int]time.Time{lockTestASN: time.Now().UTC()}
now := time.Now().UTC()
asns := map[int]SeenTimes{lockTestASN: {First: now, Last: now}}
// A stored AS gives ANALYZE a table to analyze and statistics to write.
err := db.GetOrCreateASNBatch(asns)
@@ -799,6 +842,388 @@ func TestCheckpointLockWaitEndsWithContext(t *testing.T) {
db.mu.Unlock()
}
// TestCheckpointDoesNotWaitForReader keeps a read transaction on
// live_routes_v4 open while a route is committed, then starts Checkpoint and a
// batch write together. It checks that both end within readerCheckpointLimit,
// whichever of them takes the database lock first, and that Checkpoint reports
// the part of the WAL the reader still needs as left uncopied. A TRUNCATE
// checkpoint waited the busy timeout for the reader while holding the lock
// (https://git.eeqj.de/sneak/routewatch/issues/102).
func TestCheckpointDoesNotWaitForReader(t *testing.T) {
t.Parallel()
db, err := New(&config.Config{StateDir: t.TempDir()}, logger.New())
if err != nil {
t.Fatalf("failed to create database: %v", err)
}
defer func() { _ = db.Close() }()
ctx := context.Background()
ts := time.Now().UTC()
err = db.UpsertLiveRouteBatch(
[]*LiveRoute{mkV4Route(t, "198.51.100.0/24", lockTestASN, ts)})
if err != nil {
t.Fatalf("failed to store the route the reader reads: %v", err)
}
reader, err := db.db.Conn(ctx)
if err != nil {
t.Fatalf("failed to open the reading connection: %v", err)
}
defer func() { _ = reader.Close() }()
// A plain BEGIN starts a transaction that only reads, unlike the BEGIN
// IMMEDIATE of _txlock. It keeps the snapshot its first read takes until
// it ends.
_, err = reader.ExecContext(ctx, "BEGIN")
if err != nil {
t.Fatalf("failed to begin the read transaction: %v", err)
}
defer func() { _, _ = reader.ExecContext(ctx, "ROLLBACK") }()
var routes int
err = reader.QueryRowContext(ctx,
"SELECT count(*) FROM live_routes_v4").Scan(&routes)
if err != nil {
t.Fatalf("failed to read the live routes: %v", err)
}
err = db.UpsertLiveRouteBatch(
[]*LiveRoute{mkV4Route(t, "203.0.113.0/24", lockTestASN, ts)})
if err != nil {
t.Fatalf("failed to store a route after the read: %v", err)
}
started := time.Now()
checkpointed := make(chan error, 1)
go func() { checkpointed <- db.Checkpoint(ctx) }()
// A route write, not an AS write: the first new AS loads the embedded AS
// names, which takes seconds under -race.
route := mkV4Route(t, "192.0.2.0/24", lockTestASN, ts)
written := make(chan error, 1)
go func() { written <- db.UpsertLiveRouteBatch([]*LiveRoute{route}) }()
err = <-checkpointed
if !errors.Is(err, ErrCheckpointIncomplete) {
t.Errorf("Checkpoint = %v with a reader open, want %v",
err, ErrCheckpointIncomplete)
}
took := time.Since(started)
if took >= readerCheckpointLimit {
t.Errorf("Checkpoint took %v with a reader open, want under %v",
took, readerCheckpointLimit)
}
err = <-written
if err != nil {
t.Errorf("batch write during Checkpoint: %v", err)
}
took = time.Since(started)
if took >= readerCheckpointLimit {
t.Errorf("batch write during Checkpoint ended after %v, want under %v",
took, readerCheckpointLimit)
}
}
// TestCheckpointEmptiesWALOnceNoReadIsOpen fills the WAL file past
// sqliteWALSizeLimitBytes while the test holds a read open. With the read
// open, it checks that Checkpoint gives up within truncateCheckpointLimit and
// reports the checkpoint incomplete, and that a batch write still succeeds.
// After the test closes the read, it checks that the next Checkpoint brings
// the WAL file under the limit and gives the writing connection its busy
// timeout back (https://git.eeqj.de/sneak/routewatch/issues/102).
func TestCheckpointEmptiesWALOnceNoReadIsOpen(t *testing.T) {
t.Parallel()
db, err := New(&config.Config{StateDir: t.TempDir()}, logger.New())
if err != nil {
t.Fatalf("failed to create database: %v", err)
}
defer func() { _ = db.Close() }()
ctx := t.Context()
reader, err := db.db.Conn(ctx)
if err != nil {
t.Fatalf("failed to open the reading connection: %v", err)
}
defer func() { _ = reader.Close() }()
// A plain BEGIN starts a transaction that only reads, unlike the BEGIN
// IMMEDIATE of _txlock. It keeps the snapshot its first read takes until
// it ends, so no checkpoint can copy what is written after that read.
_, err = reader.ExecContext(ctx, "BEGIN")
if err != nil {
t.Fatalf("failed to begin the read transaction: %v", err)
}
var routes int
err = reader.QueryRowContext(ctx,
"SELECT count(*) FROM live_routes_v4").Scan(&routes)
if err != nil {
t.Fatalf("failed to read the live routes: %v", err)
}
fillWALPastLimit(ctx, t, db)
started := time.Now()
err = db.Checkpoint(ctx)
if !errors.Is(err, ErrCheckpointIncomplete) {
t.Errorf("Checkpoint = %v with a read open, want %v",
err, ErrCheckpointIncomplete)
}
took := time.Since(started)
if took >= truncateCheckpointLimit {
t.Errorf("Checkpoint took %v with a read open, want under %v",
took, truncateCheckpointLimit)
}
err = db.UpsertLiveRouteBatch([]*LiveRoute{
mkV4Route(t, "192.0.2.0/24", lockTestASN, time.Now().UTC()),
})
if err != nil {
t.Errorf("batch write after Checkpoint gave up: %v", err)
}
_, err = reader.ExecContext(ctx, "ROLLBACK")
if err != nil {
t.Fatalf("failed to end the read transaction: %v", err)
}
err = db.Checkpoint(ctx)
if err != nil {
t.Errorf("Checkpoint with no read open: %v", err)
}
size := walFileSize(t, db)
if size >= sqliteWALSizeLimitBytes {
t.Errorf("WAL file of %d bytes after Checkpoint with no read open, "+
"want under %d", size, sqliteWALSizeLimitBytes)
}
busyTimeout := readPragma(ctx, t, db.writer, 0, "busy_timeout")
if busyTimeout != sqliteBusyTimeoutMs {
t.Errorf("writing connection: busy_timeout = %d after the checkpoints, "+
"want %d", busyTimeout, sqliteBusyTimeoutMs)
}
}
// fillWALPastLimit writes sqliteWALSizeLimitBytes of random bytes to a table
// of the test's own, which with SQLite's page and frame headers leaves the WAL
// file of db over the limit, and checks that it does.
func fillWALPastLimit(ctx context.Context, t *testing.T, db *Database) {
t.Helper()
_, err := db.writer.ExecContext(ctx, "CREATE TABLE wal_fill (data BLOB)")
if err != nil {
t.Fatalf("failed to create the table the test writes to: %v", err)
}
_, err = db.writer.ExecContext(ctx,
"INSERT INTO wal_fill VALUES (randomblob(?))", sqliteWALSizeLimitBytes)
if err != nil {
t.Fatalf("failed to fill the WAL: %v", err)
}
size := walFileSize(t, db)
if size <= sqliteWALSizeLimitBytes {
t.Fatalf("WAL file of %d bytes after the test's write, want over %d",
size, sqliteWALSizeLimitBytes)
}
}
// walFileSize returns the size of the WAL file of db.
func walFileSize(t *testing.T, db *Database) int64 {
t.Helper()
wal, err := os.Stat(db.path + walFileSuffix)
if err != nil {
t.Fatalf("failed to read the WAL file's size: %v", err)
}
return wal.Size()
}
// TestStartupCheckpointLogsItsFigures opens a new database, writes a route,
// and opens the same file again while the first stays open, so that its WAL
// file stays. The first open finds no WAL file: it logs a size of 0 and no
// warning. The second logs the size of the WAL file the first left, and the
// checkpoint's busy flag and frame counts, each under its own name; the
// counts read 0 once the checkpoint has emptied the file.
// Initialize logged the busy flag as wal_pages and the counts under each
// other's names (https://git.eeqj.de/sneak/routewatch/issues/117).
func TestStartupCheckpointLogsItsFigures(t *testing.T) {
t.Parallel()
cfg := &config.Config{StateDir: t.TempDir()}
db, lines := openLogged(t, cfg)
for _, line := range lines {
if line[slog.LevelKey] == slog.LevelWarn.String() {
t.Errorf("opening a new database logged a warning: %v", line)
}
}
line := findLine(t, lines, startupCheckpointMessage)
if line["wal_bytes"] != 0.0 {
t.Errorf("new database: start-up checkpoint logged wal_bytes = %v, "+
"want 0", line["wal_bytes"])
}
err := db.UpsertLiveRouteBatch([]*LiveRoute{
mkV4Route(t, "192.0.2.0/24", lockTestASN, time.Now().UTC()),
})
if err != nil {
t.Fatalf("failed to store a route: %v", err)
}
walBytes := walFileSize(t, db)
if walBytes == 0 {
t.Fatal("WAL file empty after the route write, want frames in it")
}
_, lines = openLogged(t, cfg)
line = findLine(t, lines, startupCheckpointMessage)
for _, key := range []string{"busy", "wal_frames", "checkpointed_frames"} {
if line[key] != 0.0 {
t.Errorf("start-up checkpoint logged %s = %v, want 0", key, line[key])
}
}
if line["wal_bytes"] != float64(walBytes) {
t.Errorf("start-up checkpoint logged wal_bytes = %v, want the %d "+
"bytes the first database left", line["wal_bytes"], walBytes)
}
}
// TestStartupCheckpointWarnsWhenIncomplete keeps a read open on a database
// while a route is written after the read began, then opens the same file
// again. The second open's start-up checkpoint cannot copy the frames written
// after the read began, and gives up once the busy timeout has passed. It
// checks that the checkpoint is logged as a warning with busy 1 and fewer
// frames copied than the WAL holds.
func TestStartupCheckpointWarnsWhenIncomplete(t *testing.T) {
t.Parallel()
cfg := &config.Config{StateDir: t.TempDir()}
db, _ := openLogged(t, cfg)
ctx := context.Background()
reader, err := db.db.Conn(ctx)
if err != nil {
t.Fatalf("failed to open the reading connection: %v", err)
}
defer func() { _ = reader.Close() }()
// A plain BEGIN starts a transaction that only reads, unlike the BEGIN
// IMMEDIATE of _txlock. It keeps the snapshot its first read takes until
// it ends.
_, err = reader.ExecContext(ctx, "BEGIN")
if err != nil {
t.Fatalf("failed to begin the read transaction: %v", err)
}
defer func() { _, _ = reader.ExecContext(ctx, "ROLLBACK") }()
var routes int
err = reader.QueryRowContext(ctx,
"SELECT count(*) FROM live_routes_v4").Scan(&routes)
if err != nil {
t.Fatalf("failed to read the live routes: %v", err)
}
err = db.UpsertLiveRouteBatch([]*LiveRoute{
mkV4Route(t, "192.0.2.0/24", lockTestASN, time.Now().UTC()),
})
if err != nil {
t.Fatalf("failed to store a route after the read: %v", err)
}
_, lines := openLogged(t, cfg)
line := findLine(t, lines, startupCheckpointIncompleteMessage)
if line[slog.LevelKey] != slog.LevelWarn.String() {
t.Errorf("start-up checkpoint logged at level %v, want %s",
line[slog.LevelKey], slog.LevelWarn)
}
if line["busy"] != 1.0 {
t.Errorf("start-up checkpoint logged busy = %v, want 1", line["busy"])
}
walFrames, _ := line["wal_frames"].(float64)
checkpointedFrames, _ := line["checkpointed_frames"].(float64)
if checkpointedFrames >= walFrames {
t.Errorf("start-up checkpoint logged checkpointed_frames = %v and "+
"wal_frames = %v with a read open, want fewer copied than the WAL "+
"holds", line["checkpointed_frames"], line["wal_frames"])
}
}
// openLogged opens the database of cfg with a logger that writes JSON, and
// returns it with the lines it logged while it opened, decoded.
func openLogged(t *testing.T, cfg *config.Config) (*Database, []map[string]any) {
t.Helper()
var logged bytes.Buffer
db, err := New(cfg,
&logger.Logger{Logger: slog.New(slog.NewJSONHandler(&logged, nil))})
if err != nil {
t.Fatalf("failed to open the database: %v", err)
}
t.Cleanup(func() { _ = db.Close() })
var lines []map[string]any
decoder := json.NewDecoder(&logged)
for decoder.More() {
var line map[string]any
err := decoder.Decode(&line)
if err != nil {
t.Fatalf("failed to decode the log: %v", err)
}
lines = append(lines, line)
}
return db, lines
}
// findLine returns the first of lines logged with message.
func findLine(
t *testing.T,
lines []map[string]any,
message string,
) map[string]any {
t.Helper()
for _, line := range lines {
if line[slog.MessageKey] == message {
return line
}
}
t.Fatalf("no line %q in the log", message)
return nil
}
// TestGetRandomPrefixesByLengthListsPrefixOnce stores one prefix of each
// family learned from two peers in the same second and checks that the
// prefix-length sample lists each of them once.
@@ -1214,6 +1639,138 @@ func TestLiveRouteUpdateSetsOriginWhenItChanges(t *testing.T) {
}
}
// TestGetASDetailsListsEachPrefixOnce stores two IPv4 prefixes and an IPv6
// prefix an AS originates, two of them from two peers at different times, and
// a prefix another AS originates. The AS details list each of the AS's
// prefixes once, IPv4 first and in text order, with its mask length and the
// time of its newest route.
func TestGetASDetailsListsEachPrefixOnce(t *testing.T) {
t.Parallel()
db, err := New(&config.Config{StateDir: t.TempDir()}, logger.New())
if err != nil {
t.Fatalf("failed to create database: %v", err)
}
defer func() { _ = db.Close() }()
const asn, otherASN = 64500, 64501
ts := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
_, err = db.GetOrCreateASN(asn, ts)
if err != nil {
t.Fatalf("GetOrCreateASN: %v", err)
}
v4Older := mkV4Route(t, "192.0.2.0/24", asn, ts)
v4Newer := mkV4Route(t, "192.0.2.0/24", asn, ts.Add(time.Minute))
v4Newer.PeerIP = secondV4PeerIP
v4Single := mkV4Route(t, "198.51.100.128/25", asn, ts)
v6Newer := mkV6Route(testV6Prefix, asn, ts.Add(time.Minute))
v6Older := mkV6Route(testV6Prefix, asn, ts)
v6Older.PeerIP = secondV6PeerIP
other := mkV4Route(t, "203.0.113.0/24", otherASN, ts)
err = db.UpsertLiveRouteBatch([]*LiveRoute{
v4Older, v4Newer, v4Single, v6Newer, v6Older, other,
})
if err != nil {
t.Fatalf("UpsertLiveRouteBatch: %v", err)
}
_, prefixes, err := db.GetASDetails(asn)
if err != nil {
t.Fatalf("GetASDetails: %v", err)
}
want := []*LiveRoute{v4Newer, v4Single, v6Newer}
listedOnce := slices.EqualFunc(prefixes, want,
func(got LiveRoute, want *LiveRoute) bool {
return got.Prefix == want.Prefix &&
got.MaskLength == want.MaskLength &&
got.IPVersion == want.IPVersion &&
got.OriginASN == asn &&
got.LastUpdated.Equal(want.LastUpdated)
})
if !listedOnce {
t.Errorf("GetASDetails listed %+v, want the prefixes and times of %+v",
prefixes, want)
}
}
// TestASPrefixQueriesUseCoveringIndexes checks the plan of each query that
// lists the prefixes an AS originates: a search of a covering index and no
// temporary B-tree, so the list reads one index entry per prefix, not one
// table row per route. Grouping the AS's routes by prefix read every route's
// row and sorted them in a temporary B-tree
// (https://git.eeqj.de/sneak/routewatch/issues/104).
func TestASPrefixQueriesUseCoveringIndexes(t *testing.T) {
t.Parallel()
db, err := New(&config.Config{StateDir: t.TempDir()}, logger.New())
if err != nil {
t.Fatalf("failed to create database: %v", err)
}
defer func() { _ = db.Close() }()
tests := []struct {
query string
args []any
index string
}{
{nextOriginPrefixV4SQL, []any{0, ""}, "idx_live_routes_v4_origin_prefix"},
{newestRouteTimeV4SQL, []any{""}, "idx_live_routes_v4_prefix_last_updated"},
{nextOriginPrefixV6SQL, []any{0, ""}, "idx_live_routes_v6_origin_prefix"},
{newestRouteTimeV6SQL, []any{""}, "idx_live_routes_v6_prefix_last_updated"},
}
for _, tt := range tests {
plan := queryPlan(t, db, tt.query, tt.args...)
if !strings.Contains(plan, "USING COVERING INDEX "+tt.index+" ") ||
strings.Contains(plan, "TEMP B-TREE") {
t.Errorf("plan of %s:\n%s\nwant a search of covering index %s "+
"and no temporary B-tree", tt.query, plan, tt.index)
}
}
}
// queryPlan returns the steps of EXPLAIN QUERY PLAN for query, one per line.
func queryPlan(t *testing.T, db *Database, query string, args ...any) string {
t.Helper()
rows, err := db.db.QueryContext(t.Context(), "EXPLAIN QUERY PLAN "+query,
args...)
if err != nil {
t.Fatalf("EXPLAIN QUERY PLAN %s: %v", query, err)
}
defer func() { _ = rows.Close() }()
var steps []string
for rows.Next() {
var (
id, parent, unused int
detail string
)
err := rows.Scan(&id, &parent, &unused, &detail)
if err != nil {
t.Fatalf("reading the plan of %s: %v", query, err)
}
steps = append(steps, detail)
}
err = rows.Err()
if err != nil {
t.Fatalf("reading the plan of %s: %v", query, err)
}
return strings.Join(steps, "\n")
}
// TestUpdatePrefixesBatchKeepsFirstSeen writes a prefix, then a batch with it
// and a new prefix. Only the new prefix is inserted and counted, and the known
// one keeps its first_seen time.
@@ -1281,6 +1838,48 @@ func TestUpdatePrefixesBatchKeepsFirstSeen(t *testing.T) {
}
}
// TestUpdatePeerBatchStoresTheEarliestAndLatestTimesOfANewPeer writes a new
// peer whose updates span 5 seconds. Its row is first seen at the earliest time
// and last seen at the latest.
func TestUpdatePeerBatchStoresTheEarliestAndLatestTimesOfANewPeer(
t *testing.T,
) {
t.Parallel()
db, err := New(&config.Config{StateDir: t.TempDir()}, logger.New())
if err != nil {
t.Fatalf("failed to create database: %v", err)
}
defer func() { _ = db.Close() }()
first := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
last := first.Add(5 * time.Second)
err = db.UpdatePeerBatch(map[string]PeerUpdate{
testPeerIP: {
PeerIP: testPeerIP, PeerASN: 64500, MessageType: "UPDATE",
Seen: SeenTimes{First: first, Last: last},
},
})
if err != nil {
t.Fatalf("UpdatePeerBatch: %v", err)
}
var firstSeen, lastSeen time.Time
err = db.db.QueryRowContext(t.Context(),
"SELECT first_seen, last_seen FROM bgp_peers WHERE peer_ip = ?",
testPeerIP).Scan(&firstSeen, &lastSeen)
if err != nil {
t.Fatalf("reading peer %s: %v", testPeerIP, err)
}
if !firstSeen.Equal(first) || !lastSeen.Equal(last) {
t.Errorf("peer %s: first seen %s, last seen %s; want %s, %s",
testPeerIP, firstSeen, lastSeen, first, last)
}
}
// TestUpsertLiveRouteBatchWritesInKeyOrder writes new routes of two peers out
// of key order, the last one a second announcement of the first, and checks
// that the rows were inserted in key order, peer then prefix (each new row's id
@@ -1518,3 +2117,66 @@ func writeBenchBatch(
b.Fatalf("UpdatePrefixesBatch: %v", err)
}
}
// Parameters for BenchmarkGetASDetailsWithFiveHundredPeers: the AS originates
// benchASPrefixes prefixes and every one of benchASPeers peers has a route for
// each, 2.5 million routes in all.
const (
benchASPrefixes = 5000
benchASPeers = 500
)
// BenchmarkGetASDetailsWithFiveHundredPeers times the read behind the AS page
// for an AS that originates 5,000 IPv4 prefixes, each from 500 peers. It
// builds that database first, one peer at a time, which takes some minutes and
// about a GB of disk under TMPDIR. It is run by hand, not by make test, for
// example in the test image:
//
// go test -run '^$' -bench GetASDetails -benchtime 10x ./internal/database/
func BenchmarkGetASDetailsWithFiveHundredPeers(b *testing.B) {
db, err := New(&config.Config{StateDir: b.TempDir()}, logger.New())
if err != nil {
b.Fatalf("failed to create database: %v", err)
}
defer func() { _ = db.Close() }()
ts := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
_, err = db.GetOrCreateASN(benchFirstASN, ts)
if err != nil {
b.Fatalf("GetOrCreateASN: %v", err)
}
for peer := range benchASPeers {
peerIP := fmt.Sprintf("198.18.%d.%d", peer/256, peer%256)
routes := make([]*LiveRoute, 0, benchASPrefixes)
for prefix := range benchASPrefixes {
routes = append(routes, &LiveRoute{
Prefix: fmt.Sprintf("%d.%d.%d.0/%d",
1+prefix>>16, (prefix>>8)%256, prefix%256, benchMaskLength),
MaskLength: benchMaskLength,
IPVersion: ipVersionV4,
OriginASN: benchFirstASN,
PeerIP: peerIP,
ASPath: []int{benchFirstASN + 1 + peer, benchFirstASN},
NextHop: peerIP,
LastUpdated: ts,
})
}
writeBenchBatch(b, db, routes, nil, ts)
}
for b.Loop() {
_, prefixes, err := db.GetASDetails(benchFirstASN)
if err != nil {
b.Fatalf("GetASDetails: %v", err)
}
if len(prefixes) != benchASPrefixes {
b.Fatalf("GetASDetails listed %d prefixes, want %d",
len(prefixes), benchASPrefixes)
}
}
}
@@ -0,0 +1,61 @@
package database
import (
"os"
"path/filepath"
"strings"
"testing"
"git.eeqj.de/sneak/routewatch/internal/config"
"git.eeqj.de/sneak/routewatch/internal/logger"
)
// TestDockerignoreExcludesDatabaseFiles checks that .dockerignore keeps the
// database file, and the WAL and shared-memory files SQLite writes next to it,
// out of the build context wherever they sit in the clone. The image ships the
// whole build context as a source archive.
func TestDockerignoreExcludesDatabaseFiles(t *testing.T) {
t.Parallel()
db, err := New(&config.Config{StateDir: t.TempDir()}, logger.New())
if err != nil {
t.Fatalf("failed to create database: %v", err)
}
defer func() { _ = db.Close() }()
data, err := os.ReadFile("../../.dockerignore")
if err != nil {
t.Fatalf("failed to read .dockerignore: %v", err)
}
// Docker reads `**/` as any number of directories and the rest of the
// pattern as filepath.Match does, so `**/` followed by a pattern that
// matches a file's name excludes that file at any depth.
var anyDepth []string
for line := range strings.Lines(string(data)) {
pattern, ok := strings.CutPrefix(strings.TrimSpace(line), "**/")
if ok {
anyDepth = append(anyDepth, pattern)
}
}
name := filepath.Base(db.path)
for _, file := range []string{name, name + "-wal", name + "-shm"} {
excluded := false
for _, pattern := range anyDepth {
matched, err := filepath.Match(pattern, file)
if err != nil {
t.Fatalf("bad .dockerignore pattern **/%s: %v", pattern, err)
}
excluded = excluded || matched
}
if !excluded {
t.Errorf(".dockerignore has no **/ pattern that excludes %s", file)
}
}
}
+2 -2
View File
@@ -34,7 +34,7 @@ type Stats struct {
type Store interface {
// ASN operations
GetOrCreateASN(number int, timestamp time.Time) (*ASN, error)
GetOrCreateASNBatch(asns map[int]time.Time) error
GetOrCreateASNBatch(asns map[int]SeenTimes) error
// Prefix operations
GetOrCreatePrefix(prefix string, timestamp time.Time) (*Prefix, error)
@@ -44,7 +44,7 @@ type Store interface {
RecordAnnouncement(announcement *Announcement) error
// Peering operations
RecordPeering(asA, asB int, timestamp time.Time) error
RecordPeering(asA, asB int, seen SeenTimes) error
// Statistics
GetStats() (Stats, error)
+25 -2
View File
@@ -122,12 +122,35 @@ type LiveRouteDeletion struct {
IPVersion int
}
// PeerUpdate represents parameters for updating a peer
// SeenTimes is the earliest and the latest time one batch of updates saw an AS,
// a peer or a peering. A row the batch adds is stored first seen at First and
// last seen at Last; a row already stored keeps its first_seen and has its
// last_seen set to Last.
type SeenTimes struct {
First time.Time
Last time.Time
}
// Add makes t the earliest time of s when it is earlier than First, and the
// latest when it is later than Last. The zero SeenTimes holds no time yet, so
// the first Add sets both.
func (s *SeenTimes) Add(t time.Time) {
if s.First.IsZero() || t.Before(s.First) {
s.First = t
}
if s.Last.IsZero() || t.After(s.Last) {
s.Last = t
}
}
// PeerUpdate represents parameters for updating a peer. PeerASN and
// MessageType are those of the peer's latest update.
type PeerUpdate struct {
PeerIP string
PeerASN int
MessageType string
Timestamp time.Time
Seen SeenTimes
}
// ASNWHOISUpdate contains WHOIS data for updating an ASN record.
+5 -4
View File
@@ -128,7 +128,7 @@ CREATE TABLE IF NOT EXISTS live_routes_v6 (
-- prefix, last_updated: a prefix's routes, for the prefix page and its API
-- answer, the IP lookup and its peer count, and the check whether a prefix
-- still has a live route; and a prefix's newest route for the prefix-length
-- pages, in one search whatever the number of peers.
-- pages and the AS page, in one search whatever the number of peers.
CREATE INDEX IF NOT EXISTS idx_live_routes_v4_prefix_last_updated ON live_routes_v4(prefix, last_updated);
CREATE INDEX IF NOT EXISTS idx_live_routes_v6_prefix_last_updated ON live_routes_v6(prefix, last_updated);
-- mask_length: the prefix-length pages' random sample, the row id range of a
@@ -139,9 +139,10 @@ CREATE INDEX IF NOT EXISTS idx_live_routes_v6_mask_length ON live_routes_v6(mask
-- prefixes in text order, and the prefix distribution read at startup.
CREATE INDEX IF NOT EXISTS idx_live_routes_v4_mask_prefix ON live_routes_v4(mask_length, prefix);
CREATE INDEX IF NOT EXISTS idx_live_routes_v6_mask_prefix ON live_routes_v6(mask_length, prefix);
-- origin_asn: the prefixes an AS originates, for the AS page and its API answer.
CREATE INDEX IF NOT EXISTS idx_live_routes_v4_origin_asn ON live_routes_v4(origin_asn);
CREATE INDEX IF NOT EXISTS idx_live_routes_v6_origin_asn ON live_routes_v6(origin_asn);
-- origin_asn, prefix: the prefixes an AS originates, each in one search
-- whatever the number of peers, for the AS page and its API answer.
CREATE INDEX IF NOT EXISTS idx_live_routes_v4_origin_prefix ON live_routes_v4(origin_asn, prefix);
CREATE INDEX IF NOT EXISTS idx_live_routes_v6_origin_prefix ON live_routes_v6(origin_asn, prefix);
-- last_updated: the oldest and newest route times in /api/v1/stats and
-- /status.json.
CREATE INDEX IF NOT EXISTS idx_live_routes_v4_last_updated ON live_routes_v4(last_updated);
+27 -9
View File
@@ -4,6 +4,7 @@ package ristypes
import (
"encoding/json"
"slices"
"time"
)
@@ -24,7 +25,8 @@ const (
)
// ASPath is a BGP AS path as the feed writes it: an array of AS numbers in
// which an AS set is an array of its members, such as [1, 2, [3, 4]].
// which an AS set is an array of its members, such as [1, 2, [3, 4]]. A path
// that holds AS 0 decodes as an empty one (UnmarshalJSON).
type ASPath struct {
// Sequence is the path's AS numbers in order. A set of one member that
// ends the path counts as that AS and is its last element. The members of
@@ -48,23 +50,41 @@ func (p *ASPath) Origin() int {
return p.Sequence[len(p.Sequence)-1]
}
// UnmarshalJSON implements the json.Unmarshaler interface for ASPath.
// UnmarshalJSON implements the json.Unmarshaler interface for ASPath. A path
// that holds AS 0 anywhere, a member of an AS set included, decodes as an empty
// path: RFC 7607 makes such a path malformed and its announcements
// withdrawals. On an announcement with an empty path the prefix handler
// deletes the peer's route, and the AS and peering handlers record nothing.
func (p *ASPath) UnmarshalJSON(data []byte) error {
path, err := decodeASPath(data)
if err != nil {
return err
}
if slices.Contains(path.Sequence, 0) || slices.Contains(path.Set, 0) {
path = ASPath{}
}
*p = path
return nil
}
// decodeASPath decodes an AS path as the feed writes it.
func decodeASPath(data []byte) (ASPath, error) {
// Most paths have no AS set and decode as a plain array of integers.
var sequence []int
err := json.Unmarshal(data, &sequence)
if err == nil {
*p = ASPath{Sequence: sequence}
return nil
return ASPath{Sequence: sequence}, nil
}
var raw []any
err = json.Unmarshal(data, &raw)
if err != nil {
return err
return ASPath{}, err
}
path := ASPath{Sequence: make([]int, 0, len(raw))}
@@ -90,9 +110,7 @@ func (p *ASPath) UnmarshalJSON(data []byte) error {
}
}
*p = path
return nil
return path, nil
}
// RISLiveMessage represents the outer wrapper message from the RIPE RIS Live stream.
+30
View File
@@ -145,3 +145,33 @@ func TestASPathKeepsATrailingSetApart(t *testing.T) {
})
}
}
// TestASPathWithASZeroDecodesAsAnEmptyPath decodes AS paths that hold AS 0
// before their end, at their end, or in an AS set. RFC 7607 makes such a path
// malformed, so each decodes as an empty path.
func TestASPathWithASZeroDecodesAsAnEmptyPath(t *testing.T) {
t.Parallel()
for _, path := range []string{
"[64496, 0, 64497]",
"[64496, 0]",
"[64496, [0, 64497], 64498]",
"[64496, [64497, 0]]",
} {
t.Run(path, func(t *testing.T) {
t.Parallel()
var got ristypes.ASPath
err := json.Unmarshal([]byte(path), &got)
if err != nil {
t.Fatalf("unmarshal %s: %v", path, err)
}
if len(got.Sequence) > 0 || len(got.Set) > 0 {
t.Errorf("%s decoded to sequence %v and set %v, want an empty path",
path, got.Sequence, got.Set)
}
})
}
}
+47 -23
View File
@@ -116,17 +116,18 @@ func (rw *RouteWatch) Run(ctx context.Context) error {
return err
}
// Start ASN WHOIS fetcher for background updates. The HTTP handlers read
// the server's fetcher without a lock, so it is set before they run.
rw.asnFetcher = NewASNFetcher(rw.db, rw.logger.Logger)
rw.asnFetcher.Start(ctx)
rw.server.SetASNFetcher(rw.asnFetcher)
// Start HTTP server
err = rw.server.Start(ctx)
if err != nil {
return err
}
// Start ASN WHOIS fetcher for background updates
rw.asnFetcher = NewASNFetcher(rw.db, rw.logger.Logger)
rw.asnFetcher.Start(ctx)
rw.server.SetASNFetcher(rw.asnFetcher)
// Start database maintenance goroutine
rw.dbMaintainer = NewDBMaintainer(rw.db, rw.logger.Logger)
rw.dbMaintainer.Start(ctx)
@@ -137,7 +138,12 @@ func (rw *RouteWatch) Run(ctx context.Context) error {
return nil
}
// Shutdown performs graceful shutdown of all services
// Shutdown stops all services in order: the streamer, the handlers, which
// write what they hold, the WHOIS fetcher, the database maintainer and the
// HTTP server, and last the database, which it checkpoints and closes. Each
// stage waits at most until ctx ends, so Shutdown returns soon after: a
// handler logs what it could not write by then, and the HTTP server closes
// the connections of requests still running.
func (rw *RouteWatch) Shutdown(ctx context.Context) {
rw.mu.Lock()
if rw.shutdown {
@@ -150,51 +156,48 @@ func (rw *RouteWatch) Shutdown(ctx context.Context) {
rw.mu.Unlock()
// Stop the streamer first: it returns once the handlers have been handed
// every message it queued. Then each handler writes what it holds.
rw.streamer.Stop()
// every message it queued, or when ctx ends. Then each handler writes
// what it holds.
rw.streamer.Stop(ctx)
if rw.dbHandler != nil {
rw.logger.Info("Flushing database handler")
rw.dbHandler.Stop()
rw.dbHandler.Stop(ctx)
}
if rw.peerHandler != nil {
rw.logger.Info("Flushing peer handler")
rw.peerHandler.Stop()
rw.peerHandler.Stop(ctx)
}
if rw.prefixHandler != nil {
rw.logger.Info("Flushing prefix handler")
rw.prefixHandler.Stop()
rw.prefixHandler.Stop(ctx)
}
if rw.peeringHandler != nil {
rw.logger.Info("Flushing peering handler")
rw.peeringHandler.Stop()
rw.peeringHandler.Stop(ctx)
}
// Stop ASN WHOIS fetcher
if rw.asnFetcher != nil {
rw.asnFetcher.Stop()
rw.asnFetcher.Stop(ctx)
}
// Stop database maintainer
if rw.dbMaintainer != nil {
rw.dbMaintainer.Stop()
rw.dbMaintainer.Stop(ctx)
}
// Stop HTTP server with a timeout of its own, however much of ctx is left
const serverStopTimeout = 5 * time.Second
stopCtx, cancel := context.WithTimeout(
context.WithoutCancel(ctx), serverStopTimeout)
defer cancel()
err := rw.server.Stop(stopCtx)
err := rw.server.Stop(ctx)
if err != nil {
rw.logger.Error("Failed to stop HTTP server gracefully", "error", err)
rw.logger.Error("Stopped the HTTP server before every request finished",
"error", err)
}
rw.closeDatabase(ctx)
// Log final metrics
metrics := rw.streamer.GetMetrics()
rw.logger.Info("Final metrics",
@@ -206,6 +209,27 @@ func (rw *RouteWatch) Shutdown(ctx context.Context) {
)
}
// closeDatabase checkpoints and closes the database, unless ctx has ended: a
// write may then still be running, and both would wait for it. SQLite rolls
// back a write cut off by the exit when the database next opens.
func (rw *RouteWatch) closeDatabase(ctx context.Context) {
if ctx.Err() != nil {
rw.logger.Error("Stop deadline passed; the database is not closed")
return
}
err := rw.db.Checkpoint(ctx)
if err != nil {
rw.logger.Error("Failed to checkpoint the database", "error", err)
}
err = rw.db.Close()
if err != nil {
rw.logger.Error("Failed to close the database", "error", err)
}
}
// getModule provides all fx dependencies
func getModule() []fx.Option {
return []fx.Option{
@@ -4,8 +4,11 @@ import (
"context"
"fmt"
"io"
"net"
"net/http"
"net/http/httptest"
"slices"
"strconv"
"strings"
"sync"
"testing"
@@ -149,7 +152,7 @@ func (m *mockStore) RecordAnnouncement(_ *database.Announcement) error {
}
// RecordPeering mock implementation
func (m *mockStore) RecordPeering(asA, asB int, _ time.Time) error {
func (m *mockStore) RecordPeering(asA, asB int, _ database.SeenTimes) error {
m.mu.Lock()
defer m.mu.Unlock()
@@ -393,16 +396,16 @@ func (m *mockStore) DeleteLiveRoutesOfPeer(_ string) (int, error) {
}
// GetOrCreateASNBatch mock implementation
func (m *mockStore) GetOrCreateASNBatch(asns map[int]time.Time) error {
func (m *mockStore) GetOrCreateASNBatch(asns map[int]database.SeenTimes) error {
m.mu.Lock()
defer m.mu.Unlock()
for number, timestamp := range asns {
for number, seen := range asns {
if _, exists := m.ASNs[number]; !exists {
m.ASNs[number] = &database.ASN{
ASN: number,
FirstSeen: timestamp,
LastSeen: timestamp,
FirstSeen: seen.First,
LastSeen: seen.Last,
}
m.ASNCount++
}
@@ -643,3 +646,189 @@ func TestShutdownWritesTheUpdatesQueuedInTheStreamer(t *testing.T) {
}
}
}
// freePort returns a TCP port that was free a moment ago, for a server the
// test starts.
func freePort(t *testing.T) int {
t.Helper()
var listenConfig net.ListenConfig
listener, err := listenConfig.Listen(t.Context(), "tcp", ":0")
if err != nil {
t.Fatalf("failed to find a free port: %v", err)
}
defer func() { _ = listener.Close() }()
addr, ok := listener.Addr().(*net.TCPAddr)
if !ok {
t.Fatalf("listener address %v is not a TCP address", listener.Addr())
}
return addr.Port
}
// 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.
// 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
)
blocking := newBlockingStore()
defer blocking.releaseWrites()
store := &closeOrderStore{Store: blocking}
log := logger.New()
port := freePort(t)
cfg := &config.Config{Port: port}
s := streamer.New(log, metrics.New())
rw := New(Dependencies{
DB: store,
Streamer: s,
Server: server.New(store, s, log, cfg),
Logger: log,
Config: cfg,
})
err := rw.server.Start(t.Context())
if err != nil {
t.Fatalf("failed to start the HTTP server: %v", err)
}
rw.dbHandler = NewASHandler(store, log)
fill := ristypes.ASPath{Sequence: slices.Repeat([]int{testASNA}, asnBatchSize)}
startBlockedWrite(t, blocking, rw.dbHandler,
[]*ristypes.RISMessage{{Path: fill}})
ctx, cancel := context.WithTimeout(t.Context(), deadline)
defer cancel()
shutDown := make(chan struct{})
go func() {
rw.Shutdown(ctx)
close(shutDown)
}()
select {
case <-shutDown:
case <-time.After(deadline + margin):
t.Fatalf("Shutdown did not return within %s of its deadline while "+
"a write was blocked", margin)
}
var dialer net.Dialer
addr := net.JoinHostPort("127.0.0.1", strconv.Itoa(port))
conn, err := dialer.DialContext(t.Context(), "tcp", addr)
if err == nil {
_ = conn.Close()
t.Errorf("the HTTP server still accepts connections on %s after "+
"Shutdown returned", addr)
}
store.callsMu.Lock()
defer store.callsMu.Unlock()
if slices.Contains(store.calls, callCheckpoint) ||
slices.Contains(store.calls, callClose) {
t.Errorf("Shutdown made the calls %q past its deadline, want no %s "+
"and no %s", store.calls, callCheckpoint, callClose)
}
}
// closeOrderStore is a store that records, in order, the AS writes,
// checkpoints and closes it is given. It passes the AS writes on to Store.
type closeOrderStore struct {
database.Store
callsMu sync.Mutex
calls []string
}
// The calls closeOrderStore records.
const (
callWrite = "AS write"
callCheckpoint = "checkpoint"
callClose = "close"
)
func (s *closeOrderStore) GetOrCreateASNBatch(
asns map[int]database.SeenTimes,
) error {
s.record(callWrite)
return s.Store.GetOrCreateASNBatch(asns)
}
func (s *closeOrderStore) Checkpoint(_ context.Context) error {
s.record(callCheckpoint)
return nil
}
func (s *closeOrderStore) Close() error {
s.record(callClose)
return nil
}
func (s *closeOrderStore) record(call string) {
s.callsMu.Lock()
defer s.callsMu.Unlock()
s.calls = append(s.calls, call)
}
// TestShutdownCheckpointsAndClosesTheDatabaseLast hands the AS handler one
// message and shuts down with time to spare. The handler's last write must
// come first, then a checkpoint, then the close. Before the fix Shutdown
// neither checkpointed nor closed the database.
func TestShutdownCheckpointsAndClosesTheDatabaseLast(t *testing.T) {
t.Parallel()
const deadline = 10 * time.Second
store := &closeOrderStore{Store: newMockStore()}
log := logger.New()
cfg := &config.Config{}
s := streamer.New(log, metrics.New())
rw := New(Dependencies{
DB: store,
Streamer: s,
Server: server.New(store, s, log, cfg),
Logger: log,
Config: cfg,
})
rw.dbHandler = NewASHandler(store, log)
rw.dbHandler.HandleMessage(&ristypes.RISMessage{
Path: ristypes.ASPath{Sequence: []int{testASNA}},
})
ctx, cancel := context.WithTimeout(t.Context(), deadline)
defer cancel()
rw.Shutdown(ctx)
store.callsMu.Lock()
defer store.callsMu.Unlock()
want := []string{callWrite, callCheckpoint, callClose}
if !slices.Equal(store.calls, want) {
t.Errorf("Shutdown made the calls %q, want %q", store.calls, want)
}
}
+55 -27
View File
@@ -1,6 +1,7 @@
package routewatch
import (
"context"
"slices"
"sync"
"time"
@@ -39,18 +40,23 @@ type ASHandler struct {
db database.Store
logger *logger.Logger
// Batching. mu guards batch only: the flush goroutine takes the batch
// under mu and writes it after releasing mu, so HandleMessage waits for
// a database write only while batch is at asnBatchMaxSize.
// Batching. mu guards batch and writing only: the flush goroutine takes
// the batch under mu and writes it after releasing mu, so HandleMessage
// waits for a database write only while batch is at asnBatchMaxSize.
mu sync.Mutex
batch []asnOp
// writing is how many operations the flush goroutine took from batch
// and has not finished writing.
writing int
// batchTaken is signalled when the flush goroutine takes batch; its L is
// &mu.
batchTaken sync.Cond
batchFullCh chan struct{} // wakes the flush goroutine when batch is full
lastFlush time.Time // used only by the flush goroutine
stopCh chan struct{}
wg sync.WaitGroup
// stopCh hands Stop's context to the flush goroutine. It holds one, so
// Stop does not wait for a write in progress to hand it over.
stopCh chan context.Context
done chan struct{} // closed when the flush goroutine returns
}
type asnOp struct {
@@ -70,12 +76,12 @@ func NewASHandler(db database.Store, logger *logger.Logger) *ASHandler {
batch: make([]asnOp, 0, asnBatchSize),
batchFullCh: make(chan struct{}, 1),
lastFlush: time.Now(),
stopCh: make(chan struct{}),
stopCh: make(chan context.Context, 1),
done: make(chan struct{}),
}
h.batchTaken.L = &h.mu
// Start the flush timer goroutine
h.wg.Add(1)
go h.flushLoop()
return h
@@ -147,20 +153,32 @@ func (h *ASHandler) HandleMessage(msg *ristypes.RISMessage) {
}
}
// Stop gracefully shuts down the ASHandler by signaling the background flush
// goroutine to terminate and waiting for it to complete. Any pending ASN
// operations in the current batch are flushed to the database before Stop
// returns. This method should be called during application shutdown to ensure
// no data is lost.
func (h *ASHandler) Stop() {
close(h.stopCh)
h.wg.Wait()
// Stop stops the flush goroutine, which writes the operations the handler holds
// before it returns, and waits for it until ctx ends. Once ctx has ended the
// flush goroutine skips that last write, and a write still running is lost
// when the process exits, so Stop logs how many operations are not written.
func (h *ASHandler) Stop(ctx context.Context) {
h.stopCh <- ctx
select {
case <-h.done:
case <-ctx.Done():
}
h.mu.Lock()
unwritten := h.writing + len(h.batch)
h.mu.Unlock()
if unwritten > 0 {
h.logger.Error("Stop deadline passed before the AS handler wrote "+
"its updates", "updates", unwritten)
}
}
// flushLoop runs in a goroutine, the only one that writes the batch: it
// flushes when the batch is full, periodically, and once more on Stop.
func (h *ASHandler) flushLoop() {
defer h.wg.Done()
defer close(h.done)
ticker := time.NewTicker(asnBatchTimeout)
defer ticker.Stop()
@@ -173,9 +191,11 @@ func (h *ASHandler) flushLoop() {
}
case <-h.batchFullCh:
h.flushBatch()
case <-h.stopCh:
// Final flush
h.flushBatch()
case ctx := <-h.stopCh:
// Final flush, unless the stop deadline has passed
if ctx.Err() == nil {
h.flushBatch()
}
return
}
@@ -183,7 +203,8 @@ func (h *ASHandler) flushLoop() {
}
// takeBatch returns the pending operations and leaves an empty batch in their
// place for HandleMessage to fill.
// place for HandleMessage to fill. They count in writing until flushBatch has
// written them.
func (h *ASHandler) takeBatch() []asnOp {
h.mu.Lock()
defer h.mu.Unlock()
@@ -193,6 +214,7 @@ func (h *ASHandler) takeBatch() []asnOp {
}
batch := h.batch
h.writing = len(batch)
h.batch = make([]asnOp, 0, asnBatchSize)
h.batchTaken.Broadcast()
@@ -207,20 +229,26 @@ func (h *ASHandler) flushBatch() {
return
}
// Process ASNs first (deduped)
asnMap := make(map[int]time.Time)
// The earliest and the latest time the batch saw each AS. The batch holds
// several updates for an AS, from many peers, so a new AS is stored first
// seen at the earliest of them and last seen at the latest.
asns := make(map[int]database.SeenTimes)
for _, op := range batch {
if existing, ok := asnMap[op.number]; !ok || op.timestamp.After(existing) {
asnMap[op.number] = op.timestamp
}
seen := asns[op.number]
seen.Add(op.timestamp)
asns[op.number] = seen
}
// Process all ASNs in a single batch transaction
err := h.db.GetOrCreateASNBatch(asnMap)
err := h.db.GetOrCreateASNBatch(asns)
if err != nil {
h.logger.Error("Failed to process ASN batch",
"error", err, "count", len(asnMap))
"error", err, "count", len(asns))
}
h.mu.Lock()
h.writing = 0
h.mu.Unlock()
h.lastFlush = time.Now()
}
@@ -0,0 +1,68 @@
package routewatch
import (
"maps"
"slices"
"testing"
"git.eeqj.de/sneak/routewatch/internal/logger"
)
// TestASHandlerStoresTheEarliestAndLatestTimesOfANewAS handles two updates
// whose path carries an AS the database does not hold yet, the second 5
// seconds after the first, in one batch into a real database. The AS is stored
// first seen at the time of the first update and last seen at the time of the
// second.
func TestASHandlerStoresTheEarliestAndLatestTimesOfANewAS(t *testing.T) {
t.Parallel()
db := newTestDatabase(t)
// Built without NewASHandler's flush goroutine, so the test flushes itself.
h := &ASHandler{db: db, logger: logger.New()}
first := peerAnnouncement(testPeerIP, testV4Prefix)
second := peerAnnouncement(testPeerIP, testV4Prefix)
second.ParsedTimestamp = first.ParsedTimestamp.Add(secondUpdateAfter)
h.HandleMessage(first)
h.HandleMessage(second)
h.flushBatch()
asn, _, err := db.GetASDetails(testASNA)
if err != nil {
t.Fatalf("GetASDetails(%d): %v", testASNA, err)
}
if !asn.FirstSeen.Equal(first.ParsedTimestamp) {
t.Errorf("first_seen of AS%d = %s, want %s", testASNA,
asn.FirstSeen, first.ParsedTimestamp)
}
if !asn.LastSeen.Equal(second.ParsedTimestamp) {
t.Errorf("last_seen of AS%d = %s, want %s", testASNA,
asn.LastSeen, second.ParsedTimestamp)
}
}
// TestASHandlerRecordsNothingFromAPathWithASZero handles an update whose AS
// path holds AS 0 between two other ASes. RFC 7607 makes such a path
// malformed, so neither AS is recorded.
func TestASHandlerRecordsNothingFromAPathWithASZero(t *testing.T) {
t.Parallel()
store := newMockStore()
// Built without NewASHandler's flush goroutine, so the test flushes itself.
h := &ASHandler{db: store, logger: logger.New()}
msg := peerAnnouncement(testPeerIP, testV4Prefix)
msg.Path = decodePath(t, testASNA, 0, testASNB)
h.HandleMessage(msg)
h.flushBatch()
if len(store.ASNs) > 0 {
t.Errorf("ASes recorded = %v, want none",
slices.Sorted(maps.Keys(store.ASNs)))
}
}
+31 -21
View File
@@ -43,7 +43,7 @@ type ASNFetcher struct {
logger *slog.Logger
immediateQueue chan int
stopCh chan struct{}
wg sync.WaitGroup
done chan struct{} // closed when the fetcher goroutine returns
// fetchMu ensures only one fetch runs at a time
fetchMu sync.Mutex
@@ -53,7 +53,8 @@ type ASNFetcher struct {
currentInterval time.Duration
consecutiveFails int
// hourly stats tracking
// hourly stats tracking; now is the clock, time.Now except in tests
now func() time.Time
statsMu sync.Mutex
successTimes []time.Time
errorTimes []time.Time
@@ -67,7 +68,9 @@ func NewASNFetcher(db database.Store, logger *slog.Logger) *ASNFetcher {
logger: logger.With("component", "asn_fetcher"),
immediateQueue: make(chan int, immediateQueueSize),
stopCh: make(chan struct{}),
done: make(chan struct{}),
currentInterval: baseInterval,
now: time.Now,
successTimes: make([]time.Time, 0),
errorTimes: make([]time.Time, 0),
}
@@ -76,8 +79,6 @@ func NewASNFetcher(db database.Store, logger *slog.Logger) *ASNFetcher {
// Start begins the background ASN fetcher goroutine. It runs until Stop:
// the end of ctx does not stop it.
func (f *ASNFetcher) Start(ctx context.Context) {
f.wg.Add(1)
go f.run(context.WithoutCancel(ctx))
f.logger.Info("ASN fetcher started",
@@ -87,11 +88,17 @@ func (f *ASNFetcher) Start(ctx context.Context) {
)
}
// Stop gracefully shuts down the fetcher.
func (f *ASNFetcher) Stop() {
// Stop stops the fetcher and waits, until ctx ends, for a lookup in progress to
// finish.
func (f *ASNFetcher) Stop(ctx context.Context) {
close(f.stopCh)
f.wg.Wait()
f.logger.Info("ASN fetcher stopped")
select {
case <-f.done:
f.logger.Info("ASN fetcher stopped")
case <-ctx.Done():
f.logger.Warn("Stop deadline passed before the ASN fetcher stopped")
}
}
// QueueImmediate queues an ASN for immediate WHOIS lookup.
@@ -116,7 +123,7 @@ func (f *ASNFetcher) GetStats() server.ASNFetcherStats {
f.intervalMu.Unlock()
// Prune old entries and count
cutoff := time.Now().Add(-statsWindow)
cutoff := f.now().Add(-statsWindow)
f.successTimes = pruneOldTimes(f.successTimes, cutoff)
f.errorTimes = pruneOldTimes(f.errorTimes, cutoff)
@@ -128,16 +135,15 @@ func (f *ASNFetcher) GetStats() server.ASNFetcherStats {
}
}
// pruneOldTimes removes times older than cutoff and returns the pruned slice.
// pruneOldTimes drops the times at or before cutoff from the front of times,
// which holds times in the order they were recorded, and returns the rest. It
// copies nothing, so it is cheap enough to run on every append.
func pruneOldTimes(times []time.Time, cutoff time.Time) []time.Time {
result := make([]time.Time, 0, len(times))
for _, t := range times {
if t.After(cutoff) {
result = append(result, t)
}
for len(times) > 0 && !times[0].After(cutoff) {
times = times[1:]
}
return result
return times
}
// getInterval returns the current fetch interval.
@@ -165,9 +171,11 @@ func (f *ASNFetcher) recordSuccess() {
}
f.intervalMu.Unlock()
// Record success time for stats
// Record success time for stats, dropping those older than statsWindow
f.statsMu.Lock()
f.successTimes = append(f.successTimes, time.Now())
now := f.now()
f.successTimes = pruneOldTimes(f.successTimes, now.Add(-statsWindow))
f.successTimes = append(f.successTimes, now)
f.statsMu.Unlock()
}
@@ -189,15 +197,17 @@ func (f *ASNFetcher) recordFailure() {
}
f.intervalMu.Unlock()
// Record error time for stats
// Record error time for stats, dropping those older than statsWindow
f.statsMu.Lock()
f.errorTimes = append(f.errorTimes, time.Now())
now := f.now()
f.errorTimes = pruneOldTimes(f.errorTimes, now.Add(-statsWindow))
f.errorTimes = append(f.errorTimes, now)
f.statsMu.Unlock()
}
// run is the main background loop.
func (f *ASNFetcher) run(ctx context.Context) {
defer f.wg.Done()
defer close(f.done)
timer := time.NewTimer(f.getInterval())
defer timer.Stop()
@@ -155,3 +155,83 @@ func TestFetchAndUpdateMarksAnASWithoutReferral(t *testing.T) {
baseInterval)
}
}
// TestASNFetcherStopReturnsByItsDeadline starts a fetcher, has it look up an
// AS whose WHOIS server does not answer until the test ends, and stops it with
// a short deadline while that lookup is in progress. Stop must return all the
// same instead of waiting for the lookup.
func TestASNFetcherStopReturnsByItsDeadline(t *testing.T) {
t.Parallel()
const stopDeadline = 100 * time.Millisecond
lookupStarted := make(chan struct{})
release := make(chan struct{})
f := NewASNFetcher(newMockStore(), logger.New().Logger)
f.whoisClient.DialContext = func(
context.Context, string, string,
) (net.Conn, error) {
close(lookupStarted)
<-release
return nil, syscall.ECONNREFUSED
}
f.Start(t.Context())
f.QueueImmediate(testASNA)
select {
case <-lookupStarted:
case <-time.After(handleMessageTimeout):
t.Fatal("the fetcher did not start the lookup")
}
ctx, cancel := context.WithTimeout(t.Context(), stopDeadline)
defer cancel()
if !returnsInTime(func() { f.Stop(ctx) }) {
t.Fatalf("Stop with a deadline of %s did not return while a lookup "+
"was in progress", stopDeadline)
}
close(release)
select {
case <-f.done:
case <-time.After(handleMessageTimeout):
t.Fatal("the fetcher goroutine did not return after the lookup ended")
}
}
// TestRecordKeepsOnlyTheStatsWindow records a success and a failure every
// second, by a clock the test sets, far longer than statsWindow, and never
// asks for the stats. The fetcher must keep only the times within the last
// statsWindow.
func TestRecordKeepsOnlyTheStatsWindow(t *testing.T) {
t.Parallel()
const (
records = 100_000
step = time.Second
want = int(statsWindow / step)
)
clock := time.Now()
f := NewASNFetcher(newMockStore(), logger.New().Logger)
f.now = func() time.Time { return clock }
for range records {
clock = clock.Add(step)
f.recordSuccess()
f.recordFailure()
}
if len(f.successTimes) != want || len(f.errorTimes) != want {
t.Errorf("%d success and %d error times kept, want %d of each, "+
"those of the last %s", len(f.successTimes), len(f.errorTimes),
want, statsWindow)
}
}
+227 -7
View File
@@ -1,6 +1,10 @@
package routewatch
import (
"bytes"
"context"
"encoding/json"
"log/slog"
"slices"
"sync"
"testing"
@@ -22,8 +26,9 @@ const (
)
// blockingStore is a mockStore whose batch writes for the AS, peer and prefix
// handlers wait until the test calls releaseWrites. writeStarted is closed when
// the first of them starts. It records what each write was given.
// handlers, delete of a peer's routes and peering write wait until the test
// calls releaseWrites. writeStarted is closed when the first of them starts. It
// records what each batch write was given.
type blockingStore struct {
*mockStore
@@ -61,7 +66,7 @@ func (s *blockingStore) UpsertLiveRouteBatch(routes []*database.LiveRoute) error
return nil
}
func (s *blockingStore) GetOrCreateASNBatch(asns map[int]time.Time) error {
func (s *blockingStore) GetOrCreateASNBatch(asns map[int]database.SeenTimes) error {
s.waitForRelease()
s.mu.Lock()
defer s.mu.Unlock()
@@ -85,6 +90,20 @@ func (s *blockingStore) UpdatePeerBatch(peers map[string]database.PeerUpdate) er
return nil
}
func (s *blockingStore) DeleteLiveRoutesOfPeer(peerIP string) (int, error) {
s.waitForRelease()
return s.mockStore.DeleteLiveRoutesOfPeer(peerIP)
}
func (s *blockingStore) RecordPeering(
asA, asB int, seen database.SeenTimes,
) error {
s.waitForRelease()
return s.mockStore.RecordPeering(asA, asB, seen)
}
func (s *blockingStore) waitForRelease() {
s.startOnce.Do(func() { close(s.writeStarted) })
<-s.release
@@ -96,6 +115,40 @@ func (s *blockingStore) releaseWrites() {
s.releaseOnce.Do(func() { close(s.release) })
}
// stopLog holds what a handler's Stop logs it did not write.
//
//nolint:tagliatelle // field names are the keys the handlers log
type stopLog struct {
Msg string `json:"msg"`
Updates int `json:"updates"`
PeersDown int `json:"peers_down"`
Paths int `json:"paths"`
}
// newErrorLogger returns a logger that writes only errors, as JSON lines, to
// logs.
func newErrorLogger(logs *bytes.Buffer) *logger.Logger {
return &logger.Logger{Logger: slog.New(slog.NewJSONHandler(logs,
&slog.HandlerOptions{Level: slog.LevelError}))}
}
// lastLogged decodes the last line in logs, which is the one Stop logs: a
// handler logs nothing after it.
func lastLogged(t *testing.T, logs *bytes.Buffer) stopLog {
t.Helper()
lines := bytes.Split(bytes.TrimSpace(logs.Bytes()), []byte("\n"))
var logged stopLog
err := json.Unmarshal(lines[len(lines)-1], &logged)
if err != nil {
t.Fatalf("want the error Stop logs, got %q: %v", logs.String(), err)
}
return logged
}
// returnsInTime reports whether f returns within handleMessageTimeout.
func returnsInTime(f func()) bool {
done := make(chan struct{})
@@ -151,14 +204,14 @@ func handleWhileAWriteIsBlocked(
store *blockingStore,
h interface {
HandleMessage(msg *ristypes.RISMessage)
Stop()
Stop(ctx context.Context)
},
fill []*ristypes.RISMessage,
extra *ristypes.RISMessage,
) {
t.Helper()
defer h.Stop()
defer h.Stop(t.Context())
defer store.releaseWrites()
startBlockedWrite(t, store, h, fill)
@@ -178,14 +231,14 @@ func handleAtMaxBatchSize(
store *blockingStore,
h interface {
HandleMessage(msg *ristypes.RISMessage)
Stop()
Stop(ctx context.Context)
},
fill, toMax []*ristypes.RISMessage,
extra *ristypes.RISMessage,
) {
t.Helper()
defer h.Stop()
defer h.Stop(t.Context())
defer store.releaseWrites()
startBlockedWrite(t, store, h, fill)
@@ -217,6 +270,173 @@ func handleAtMaxBatchSize(
}
}
// stopWhileAWriteIsBlocked starts a blocked write with the messages in fill,
// hands h the message extra, and stops h with a deadline that passes while
// store holds the write. Stop must return all the same. Then it lets the write
// finish and waits until done, closed when h's flush goroutine returns. Past
// the deadline that goroutine skips its last write, so extra is not written,
// and Stop logs as not written both extra and what the held write took.
func stopWhileAWriteIsBlocked(
t *testing.T,
store *blockingStore,
h interface {
HandleMessage(msg *ristypes.RISMessage)
Stop(ctx context.Context)
},
done <-chan struct{},
fill []*ristypes.RISMessage,
extra *ristypes.RISMessage,
) {
t.Helper()
const stopDeadline = 100 * time.Millisecond
defer store.releaseWrites()
startBlockedWrite(t, store, h, fill)
h.HandleMessage(extra)
ctx, cancel := context.WithTimeout(t.Context(), stopDeadline)
defer cancel()
if !returnsInTime(func() { h.Stop(ctx) }) {
t.Fatalf("Stop with a deadline of %s did not return while a write "+
"was blocked", stopDeadline)
}
store.releaseWrites()
select {
case <-done:
case <-time.After(handleMessageTimeout):
t.Fatal("the flush goroutine did not return after the write finished")
}
}
func TestPrefixHandlerSkipsItsLastWriteAfterTheStopDeadline(t *testing.T) {
t.Parallel()
const extraPrefix = "198.51.100.0/24"
var logs bytes.Buffer
store := newBlockingStore()
h := NewPrefixHandler(store, newErrorLogger(&logs))
fill := slices.Repeat([]string{testV4Prefix}, prefixBatchSize)
// The peer's session goes down first, so the write held is the delete of
// its routes, and Stop must log that peer down too.
stopWhileAWriteIsBlocked(t, store, h, h.done,
[]*ristypes.RISMessage{sessionDown(), prefixAnnouncement(fill)},
prefixAnnouncement([]string{extraPrefix}))
store.mu.Lock()
defer store.mu.Unlock()
if store.prefixes[extraPrefix] {
t.Errorf("%s was written after the stop deadline", extraPrefix)
}
logged := lastLogged(t, &logs)
if logged.Updates != prefixBatchSize+1 || logged.PeersDown != 1 {
t.Errorf("Stop logged %d updates and %d peer downs not written, "+
"want %d and 1", logged.Updates, logged.PeersDown, prefixBatchSize+1)
}
}
func TestASHandlerSkipsItsLastWriteAfterTheStopDeadline(t *testing.T) {
t.Parallel()
// Each message gives an update for its origin AS and one for each AS
// in its path: fill asnBatchSize+1, extra 2.
const wantUpdates = asnBatchSize + 1 + 2
var logs bytes.Buffer
store := newBlockingStore()
h := NewASHandler(store, newErrorLogger(&logs))
fill := ristypes.ASPath{Sequence: slices.Repeat([]int{testASNA}, asnBatchSize)}
stopWhileAWriteIsBlocked(t, store, h, h.done,
[]*ristypes.RISMessage{{Path: fill}},
&ristypes.RISMessage{Path: ristypes.ASPath{Sequence: []int{testASNB}}})
store.mu.Lock()
defer store.mu.Unlock()
if store.asns[testASNB] {
t.Errorf("AS%d was written after the stop deadline", testASNB)
}
if logged := lastLogged(t, &logs); logged.Updates != wantUpdates {
t.Errorf("Stop logged %d updates not written, want %d",
logged.Updates, wantUpdates)
}
}
func TestPeerHandlerSkipsItsLastWriteAfterTheStopDeadline(t *testing.T) {
t.Parallel()
const otherPeerIP = "2001:db8:ffff::2"
var logs bytes.Buffer
store := newBlockingStore()
h := NewPeerHandler(store, newErrorLogger(&logs))
stopWhileAWriteIsBlocked(t, store, h, h.done,
slices.Repeat([]*ristypes.RISMessage{{Peer: testPeerIP}}, peerBatchSize),
&ristypes.RISMessage{Peer: otherPeerIP})
store.mu.Lock()
defer store.mu.Unlock()
if store.peers[otherPeerIP] {
t.Errorf("peer %s was written after the stop deadline", otherPeerIP)
}
if logged := lastLogged(t, &logs); logged.Updates != peerBatchSize+1 {
t.Errorf("Stop logged %d updates not written, want %d",
logged.Updates, peerBatchSize+1)
}
}
// TestPeeringHandlerStopCountsTheWriteInProgress hands a running peering
// handler one AS path and stops it with a deadline that passes while store
// holds Stop's last write, of that path's peering. Stop must log that path as
// not written.
func TestPeeringHandlerStopCountsTheWriteInProgress(t *testing.T) {
t.Parallel()
const stopDeadline = 100 * time.Millisecond
var logs bytes.Buffer
store := newBlockingStore()
defer store.releaseWrites()
h := NewPeeringHandler(store, newErrorLogger(&logs))
handle(h, time.Now().UTC(), testASNA, testASNB)
ctx, cancel := context.WithTimeout(t.Context(), stopDeadline)
defer cancel()
if !returnsInTime(func() { h.Stop(ctx) }) {
t.Fatalf("Stop with a deadline of %s did not return while a write "+
"was blocked", stopDeadline)
}
store.releaseWrites()
select {
case <-h.done:
case <-time.After(handleMessageTimeout):
t.Fatal("the processing goroutine did not return after the write " +
"finished")
}
if logged := lastLogged(t, &logs); logged.Paths != 1 {
t.Errorf("Stop logged %d paths not written, want 1", logged.Paths)
}
}
// prefixAnnouncement returns a message in which testPeerIP announces prefixes
// with origin AS testASNA.
func prefixAnnouncement(prefixes []string) *ristypes.RISMessage {
+17 -23
View File
@@ -3,10 +3,8 @@ package routewatch
import (
"context"
"os"
"os/signal"
"runtime"
"strings"
"syscall"
"time"
"git.eeqj.de/sneak/routewatch/internal/logger"
@@ -14,8 +12,14 @@ import (
)
const (
// shutdownTimeout is the maximum time allowed for graceful shutdown
shutdownTimeout = 60 * time.Second
// shutdownTimeout is how long Shutdown has after a stop signal. upaas,
// like docker stop by default, kills the container 10 seconds after the
// stop signal (README "Running under upaas").
shutdownTimeout = 8 * time.Second
// stopTimeout is fx's limit on the stop hook, past which fx exits with
// status 1: shutdownTimeout and time for Shutdown to close the HTTP
// server after its deadline.
stopTimeout = 9 * time.Second
// debugInterval is how often to log debug stats
debugInterval = 60 * time.Second
// bytesPerMB is bytes per megabyte
@@ -56,14 +60,14 @@ func logDebugStats(logger *logger.Logger) {
}
// CLIEntry is the main entry point for the routewatch command-line interface.
// It initializes the application using the fx dependency injection framework,
// sets up signal handling for graceful shutdown, and starts the RouteWatch
// service. This function blocks until the application receives a shutdown
// signal or encounters a fatal error.
// It initializes the application using the fx dependency injection framework
// and starts the RouteWatch service. It blocks until fx receives SIGINT or
// SIGTERM or RouteWatch stops on an error; fx then runs the stop hook and sets
// the exit code.
func CLIEntry() {
app := fx.New(
fx.Options(getModule()...),
fx.StopTimeout(shutdownTimeout), // Allow 60 seconds for graceful shutdown
fx.StopTimeout(stopTimeout),
fx.Invoke(func(
lc fx.Lifecycle,
rw *RouteWatch,
@@ -75,20 +79,6 @@ func CLIEntry() {
// Start debug stats logging
go logDebugStats(logger)
// Handle shutdown signals
sigCh := make(chan os.Signal, 1)
signal.Notify(sigCh, os.Interrupt, syscall.SIGTERM)
go func() {
<-sigCh
logger.Info("Received shutdown signal")
err := shutdowner.Shutdown()
if err != nil {
logger.Error("Failed to shutdown gracefully", "error", err)
}
}()
go func() {
err := rw.Run(ctx)
if err != nil {
@@ -106,6 +96,10 @@ func CLIEntry() {
},
OnStop: func(ctx context.Context) error {
logger.Info("Shutting down RouteWatch")
ctx, cancel := context.WithTimeout(ctx, shutdownTimeout)
defer cancel()
rw.Shutdown(ctx)
return nil
+27 -10
View File
@@ -2,6 +2,7 @@ package routewatch
import (
"context"
"errors"
"log/slog"
"sync"
"time"
@@ -34,12 +35,18 @@ const (
analyzeTimeout = 5 * time.Minute
)
// checkpointIncompleteMessage is logged, at debug level like a completed
// checkpoint, when a checkpoint leaves part of the WAL for a later one: while
// reads overlap, most do. The database warns when the WAL file stays over its
// size limit.
const checkpointIncompleteMessage = "WAL checkpoint incomplete"
// DBMaintainer handles background database maintenance tasks.
type DBMaintainer struct {
db database.Store
logger *slog.Logger
stopCh chan struct{}
wg sync.WaitGroup
done chan struct{} // closed when the maintenance goroutine returns
// Stats tracking
statsMu sync.Mutex
@@ -60,14 +67,13 @@ func NewDBMaintainer(db database.Store, logger *slog.Logger) *DBMaintainer {
db: db,
logger: logger.With("component", "db_maintainer"),
stopCh: make(chan struct{}),
done: make(chan struct{}),
}
}
// Start begins the background maintenance goroutine. It runs until Stop:
// the end of ctx does not stop it.
func (m *DBMaintainer) Start(ctx context.Context) {
m.wg.Add(1)
go m.run(context.WithoutCancel(ctx))
m.logger.Info("Database maintainer started",
@@ -77,16 +83,23 @@ func (m *DBMaintainer) Start(ctx context.Context) {
)
}
// Stop gracefully shuts down the maintainer.
func (m *DBMaintainer) Stop() {
// Stop stops the maintainer and waits, until ctx ends, for a maintenance task
// in progress to finish.
func (m *DBMaintainer) Stop(ctx context.Context) {
close(m.stopCh)
m.wg.Wait()
m.logger.Info("Database maintainer stopped")
select {
case <-m.done:
m.logger.Info("Database maintainer stopped")
case <-ctx.Done():
m.logger.Warn("Stop deadline passed before the database maintainer " +
"stopped")
}
}
// run is the main background loop.
func (m *DBMaintainer) run(ctx context.Context) {
defer m.wg.Done()
defer close(m.done)
// Use different timers for each task
checkpointTimer := time.NewTimer(checkpointInterval)
@@ -123,9 +136,13 @@ func (m *DBMaintainer) runCheckpoint(ctx context.Context) {
duration, err := runWithTimeout(ctx, checkpointTimeout, m.db.Checkpoint)
m.recordResult(&m.lastCheckpoint, &m.lastCheckpointError, &m.checkpointCount, err)
if err != nil {
switch {
case errors.Is(err, database.ErrCheckpointIncomplete):
m.logger.Debug(checkpointIncompleteMessage,
"error", err, "duration", duration)
case err != nil:
m.logger.Error("WAL checkpoint failed", "error", err, "duration", duration)
} else {
default:
m.logger.Debug("WAL checkpoint completed", "duration", duration)
}
}
@@ -0,0 +1,120 @@
package routewatch
import (
"bytes"
"context"
"encoding/json"
"log/slog"
"testing"
"time"
"git.eeqj.de/sneak/routewatch/internal/database"
)
// incompleteCheckpointStore is a store whose every checkpoint leaves part of
// the WAL uncopied.
type incompleteCheckpointStore struct{ *mockStore }
// Checkpoint reports the checkpoint incomplete.
func (incompleteCheckpointStore) Checkpoint(context.Context) error {
return database.ErrCheckpointIncomplete
}
// TestIncompleteCheckpointNotLoggedAsCompleted runs a checkpoint that leaves
// part of the WAL uncopied and checks that the maintainer logs it as
// incomplete, not as completed, and does not count it as a checkpoint that
// completed.
func TestIncompleteCheckpointNotLoggedAsCompleted(t *testing.T) {
t.Parallel()
var logs bytes.Buffer
logger := slog.New(slog.NewJSONHandler(&logs,
&slog.HandlerOptions{Level: slog.LevelDebug}))
m := NewDBMaintainer(incompleteCheckpointStore{newMockStore()}, logger)
m.runCheckpoint(t.Context())
var logged struct {
Msg string `json:"msg"`
}
err := json.Unmarshal(logs.Bytes(), &logged)
if err != nil {
t.Fatalf("want one log message, got %q: %v", logs.String(), err)
}
if logged.Msg != checkpointIncompleteMessage {
t.Errorf("logged %q, want %q", logged.Msg, checkpointIncompleteMessage)
}
if m.checkpointCount != 0 {
t.Errorf("checkpointCount = %d after an incomplete checkpoint, want 0",
m.checkpointCount)
}
}
// heldCheckpointStore is a store whose checkpoint closes started and then
// waits until release is closed.
type heldCheckpointStore struct {
*mockStore
started chan struct{}
release chan struct{}
}
// Checkpoint waits until release is closed.
func (s heldCheckpointStore) Checkpoint(context.Context) error {
close(s.started)
<-s.release
return nil
}
// TestDBMaintainerStopReturnsByItsDeadline stops the maintainer with a short
// deadline while its goroutine runs a checkpoint that the store holds until
// the test ends. Stop must return all the same instead of waiting for the
// checkpoint.
func TestDBMaintainerStopReturnsByItsDeadline(t *testing.T) {
t.Parallel()
const stopDeadline = 100 * time.Millisecond
store := heldCheckpointStore{
mockStore: newMockStore(),
started: make(chan struct{}),
release: make(chan struct{}),
}
m := NewDBMaintainer(store, slog.Default())
// Start would run the first checkpoint only after checkpointInterval.
// This goroutine stands for the one Start runs and checkpoints at once.
go func() {
defer close(m.done)
m.runCheckpoint(t.Context())
}()
select {
case <-store.started:
case <-time.After(handleMessageTimeout):
t.Fatal("the maintainer did not start the checkpoint")
}
ctx, cancel := context.WithTimeout(t.Context(), stopDeadline)
defer cancel()
if !returnsInTime(func() { m.Stop(ctx) }) {
t.Fatalf("Stop with a deadline of %s did not return while a "+
"checkpoint was in progress", stopDeadline)
}
close(store.release)
select {
case <-m.done:
case <-time.After(handleMessageTimeout):
t.Fatal("the maintenance goroutine did not return after the " +
"checkpoint ended")
}
}
+63 -35
View File
@@ -5,6 +5,7 @@ package routewatch
// peer state in the database.
import (
"context"
"strconv"
"sync"
"time"
@@ -36,24 +37,30 @@ const (
// PeerHandler tracks BGP peers from UPDATE messages using batched operations.
// It maintains a queue of peer updates and periodically flushes them to the database
// in batches to improve performance. The handler deduplicates peer updates within
// each batch, keeping only the most recent update for each peer IP address.
// in batches to improve performance. The handler writes one row per peer IP
// address for each batch, with the earliest and the latest time of its updates.
type PeerHandler struct {
db database.Store
logger *logger.Logger
// Batching. mu guards peerBatch only: the flush goroutine takes the batch
// under mu and writes it after releasing mu, so HandleMessage waits for
// a database write only while peerBatch is at peerBatchMaxSize.
// Batching. mu guards peerBatch and writing only: the flush goroutine
// takes the batch under mu and writes it after releasing mu, so
// HandleMessage waits for a database write only while peerBatch is at
// peerBatchMaxSize.
mu sync.Mutex
peerBatch []peerUpdate
// writing is how many updates the flush goroutine took from peerBatch
// and has not finished writing.
writing int
// batchTaken is signalled when the flush goroutine takes peerBatch; its L
// is &mu.
batchTaken sync.Cond
batchFullCh chan struct{} // wakes the flush goroutine when peerBatch is full
lastFlush time.Time // used only by the flush goroutine
stopCh chan struct{}
wg sync.WaitGroup
// stopCh hands Stop's context to the flush goroutine. It holds one, so
// Stop does not wait for a write in progress to hand it over.
stopCh chan context.Context
done chan struct{} // closed when the flush goroutine returns
}
type peerUpdate struct {
@@ -74,12 +81,12 @@ func NewPeerHandler(db database.Store, logger *logger.Logger) *PeerHandler {
peerBatch: make([]peerUpdate, 0, peerBatchSize),
batchFullCh: make(chan struct{}, 1),
lastFlush: time.Now(),
stopCh: make(chan struct{}),
stopCh: make(chan context.Context, 1),
done: make(chan struct{}),
}
h.batchTaken.L = &h.mu
// Start the flush timer goroutine
h.wg.Add(1)
go h.flushLoop()
return h
@@ -144,16 +151,32 @@ func (h *PeerHandler) HandleMessage(msg *ristypes.RISMessage) {
}
}
// Stop gracefully stops the handler and flushes remaining batches
func (h *PeerHandler) Stop() {
close(h.stopCh)
h.wg.Wait()
// Stop stops the flush goroutine, which writes the updates the handler holds
// before it returns, and waits for it until ctx ends. Once ctx has ended the
// flush goroutine skips that last write, and a write still running is lost
// when the process exits, so Stop logs how many updates are not written.
func (h *PeerHandler) Stop(ctx context.Context) {
h.stopCh <- ctx
select {
case <-h.done:
case <-ctx.Done():
}
h.mu.Lock()
unwritten := h.writing + len(h.peerBatch)
h.mu.Unlock()
if unwritten > 0 {
h.logger.Error("Stop deadline passed before the peer handler wrote "+
"its updates", "updates", unwritten)
}
}
// flushLoop runs in a goroutine, the only one that writes the batch: it
// flushes when the batch is full, periodically, and once more on Stop.
func (h *PeerHandler) flushLoop() {
defer h.wg.Done()
defer close(h.done)
ticker := time.NewTicker(peerBatchTimeout)
defer ticker.Stop()
@@ -166,9 +189,11 @@ func (h *PeerHandler) flushLoop() {
}
case <-h.batchFullCh:
h.flushBatch()
case <-h.stopCh:
// Final flush
h.flushBatch()
case ctx := <-h.stopCh:
// Final flush, unless the stop deadline has passed
if ctx.Err() == nil {
h.flushBatch()
}
return
}
@@ -176,7 +201,8 @@ func (h *PeerHandler) flushLoop() {
}
// takeBatch returns the pending updates and leaves an empty batch in their
// place for HandleMessage to fill.
// place for HandleMessage to fill. They count in writing until flushBatch has
// written them.
func (h *PeerHandler) takeBatch() []peerUpdate {
h.mu.Lock()
defer h.mu.Unlock()
@@ -186,6 +212,7 @@ func (h *PeerHandler) takeBatch() []peerUpdate {
}
batch := h.peerBatch
h.writing = len(batch)
h.peerBatch = make([]peerUpdate, 0, peerBatchSize)
h.batchTaken.Broadcast()
@@ -200,32 +227,33 @@ func (h *PeerHandler) flushBatch() {
return
}
// Deduplicate by peer IP, keeping the latest update for each peer
peerMap := make(map[string]peerUpdate)
// The earliest and the latest time the batch saw each peer, with the peer
// AS and message type of its latest update. The batch holds several
// updates for a peer, so a new peer is stored first seen at the earliest of
// them and last seen at the latest.
peers := make(map[string]database.PeerUpdate)
for _, update := range batch {
existing, ok := peerMap[update.peerIP]
if !ok || update.timestamp.After(existing.timestamp) {
peerMap[update.peerIP] = update
peer, ok := peers[update.peerIP]
if !ok || update.timestamp.After(peer.Seen.Last) {
peer.PeerIP = update.peerIP
peer.PeerASN = update.peerASN
peer.MessageType = update.messageType
}
}
// Convert to database format
dbPeerMap := make(map[string]database.PeerUpdate)
for peerIP, update := range peerMap {
dbPeerMap[peerIP] = database.PeerUpdate{
PeerIP: update.peerIP,
PeerASN: update.peerASN,
MessageType: update.messageType,
Timestamp: update.timestamp,
}
peer.Seen.Add(update.timestamp)
peers[update.peerIP] = peer
}
// Process all peers in a single batch transaction
err := h.db.UpdatePeerBatch(dbPeerMap)
err := h.db.UpdatePeerBatch(peers)
if err != nil {
h.logger.Error("Failed to process peer batch",
"error", err, "count", len(dbPeerMap))
"error", err, "count", len(peers))
}
h.mu.Lock()
h.writing = 0
h.mu.Unlock()
h.lastFlush = time.Now()
}
@@ -0,0 +1,59 @@
package routewatch
import (
"testing"
"git.eeqj.de/sneak/routewatch/internal/database"
"git.eeqj.de/sneak/routewatch/internal/logger"
)
// peerBatchStore keeps the peers of the last UpdatePeerBatch call. The
// database has no read of the peer table, so the peer handler's test checks
// what the handler writes.
type peerBatchStore struct {
*mockStore
peers map[string]database.PeerUpdate
}
func (s *peerBatchStore) UpdatePeerBatch(
peers map[string]database.PeerUpdate,
) error {
s.peers = peers
return nil
}
// TestPeerHandlerWritesTheEarliestAndLatestTimesOfANewPeer handles two updates
// from one peer, the second 5 seconds after the first, in one batch. The peer
// handler writes the peer first seen at the time of the first update and last
// seen at the time of the second.
func TestPeerHandlerWritesTheEarliestAndLatestTimesOfANewPeer(t *testing.T) {
t.Parallel()
store := &peerBatchStore{mockStore: newMockStore()}
// Built without NewPeerHandler's flush goroutine, so the test flushes
// itself.
h := &PeerHandler{db: store, logger: logger.New()}
first := peerAnnouncement(testPeerIP, testV4Prefix)
second := peerAnnouncement(testPeerIP, testV4Prefix)
second.ParsedTimestamp = first.ParsedTimestamp.Add(secondUpdateAfter)
h.HandleMessage(first)
h.HandleMessage(second)
h.flushBatch()
seen := store.peers[testPeerIP].Seen
if !seen.First.Equal(first.ParsedTimestamp) {
t.Errorf("first_seen of peer %s = %s, want %s", testPeerIP,
seen.First, first.ParsedTimestamp)
}
if !seen.Last.Equal(second.ParsedTimestamp) {
t.Errorf("last_seen of peer %s = %s, want %s", testPeerIP,
seen.Last, second.ParsedTimestamp)
}
}
+73 -36
View File
@@ -1,6 +1,7 @@
package routewatch
import (
"context"
"encoding/json"
"sync"
"time"
@@ -41,13 +42,19 @@ type PeeringHandler struct {
db database.Store
logger *logger.Logger
// In-memory AS path tracking
// In-memory AS path tracking: each path, JSON-encoded, with the earliest
// and the latest time an update carried it.
mu sync.Mutex
asPaths map[string]time.Time // key is JSON-encoded AS path
droppedPaths int // paths dropped because the map was full
asPaths map[string]database.SeenTimes
droppedPaths int // paths dropped since the last run because the map was full
// writing is how many paths processPeerings took from asPaths and has
// not finished writing the peerings of.
writing int
stopCh chan struct{}
wg sync.WaitGroup
// stopCh hands Stop's context to the processing goroutine. It holds one,
// so Stop does not wait for a write in progress to hand it over.
stopCh chan context.Context
done chan struct{} // closed when the processing goroutine returns
}
// NewPeeringHandler creates and initializes a new PeeringHandler with the
@@ -58,13 +65,12 @@ func NewPeeringHandler(db database.Store, logger *logger.Logger) *PeeringHandler
h := &PeeringHandler{
db: db,
logger: logger,
asPaths: make(map[string]time.Time),
stopCh: make(chan struct{}),
asPaths: make(map[string]database.SeenTimes),
stopCh: make(chan context.Context, 1),
done: make(chan struct{}),
}
// Start the periodic processing goroutine
h.wg.Add(1)
go h.processLoop()
return h
@@ -113,16 +119,18 @@ func (h *PeeringHandler) HandleMessage(msg *ristypes.RISMessage) {
key := string(pathJSON)
h.mu.Lock()
if _, exists := h.asPaths[key]; exists {
// Already tracked: refresh its timestamp.
h.asPaths[key] = timestamp
} else if len(h.asPaths) >= maxTrackedPaths {
defer h.mu.Unlock()
seen, exists := h.asPaths[key]
if !exists && len(h.asPaths) >= maxTrackedPaths {
// Map is full; drop this new path and count it.
h.droppedPaths++
} else {
h.asPaths[key] = timestamp
return
}
h.mu.Unlock()
seen.Add(timestamp)
h.asPaths[key] = seen
}
// ProcessPeeringsNow triggers immediate processing of all accumulated AS
@@ -132,18 +140,33 @@ func (h *PeeringHandler) ProcessPeeringsNow() {
h.processPeerings()
}
// Stop gracefully shuts down the handler by signaling the background
// goroutine to stop and waiting while it processes the remaining AS paths,
// so no peering data is lost during shutdown.
func (h *PeeringHandler) Stop() {
close(h.stopCh)
h.wg.Wait()
// Stop stops the processing goroutine, which writes the peerings of the AS
// paths the handler holds before it returns, and waits for it until ctx ends.
// Once ctx has ended the processing goroutine skips that last write, and a
// write still running is lost when the process exits, so Stop logs how many
// paths' peerings are not written.
func (h *PeeringHandler) Stop(ctx context.Context) {
h.stopCh <- ctx
select {
case <-h.done:
case <-ctx.Done():
}
h.mu.Lock()
unwritten := h.writing + len(h.asPaths)
h.mu.Unlock()
if unwritten > 0 {
h.logger.Error("Stop deadline passed before the peering handler wrote "+
"its peerings", "paths", unwritten)
}
}
// processLoop runs periodically to process AS paths into peerings, and once
// more on Stop.
func (h *PeeringHandler) processLoop() {
defer h.wg.Done()
defer close(h.done)
ticker := time.NewTicker(peeringProcessInterval)
defer ticker.Stop()
@@ -152,9 +175,11 @@ func (h *PeeringHandler) processLoop() {
select {
case <-ticker.C:
h.processPeerings()
case <-h.stopCh:
// Final processing
h.processPeerings()
case ctx := <-h.stopCh:
// Final processing, unless the stop deadline has passed
if ctx.Err() == nil {
h.processPeerings()
}
return
}
@@ -165,11 +190,14 @@ func (h *PeeringHandler) processLoop() {
func (h *PeeringHandler) processPeerings() {
// Take the accumulated paths and replace the map with a fresh empty one
// under the lock. Each path is processed exactly once and the memory is
// released, so the map never grows past a single interval's traffic.
// released, so the map never grows past a single interval's traffic. The
// count of dropped paths starts again with the new map.
h.mu.Lock()
paths := h.asPaths
h.asPaths = make(map[string]time.Time)
h.asPaths = make(map[string]database.SeenTimes)
h.writing = len(paths)
dropped := h.droppedPaths
h.droppedPaths = 0
h.mu.Unlock()
if len(paths) == 0 {
@@ -181,9 +209,13 @@ func (h *PeeringHandler) processPeerings() {
low, high int
}
peerings := make(map[peeringKey]time.Time)
// The earliest and the latest time an update carried each peering. Several
// paths, each carried at several times, can hold a peering, so a new
// peering is stored first seen at the earliest of them and last seen at the
// latest.
peerings := make(map[peeringKey]database.SeenTimes)
for pathJSON, timestamp := range paths {
for pathJSON, pathSeen := range paths {
var path []int
err := json.Unmarshal([]byte(pathJSON), &path)
@@ -210,10 +242,11 @@ func (h *PeeringHandler) processPeerings() {
}
key := peeringKey{low: low, high: high}
// Update timestamp if this is newer
if existing, ok := peerings[key]; !ok || timestamp.After(existing) {
peerings[key] = timestamp
}
seen := peerings[key]
seen.Add(pathSeen.First)
seen.Add(pathSeen.Last)
peerings[key] = seen
}
}
@@ -221,8 +254,8 @@ func (h *PeeringHandler) processPeerings() {
start := time.Now()
successCount := 0
for key, ts := range peerings {
err := h.db.RecordPeering(key.low, key.high, ts)
for key, seen := range peerings {
err := h.db.RecordPeering(key.low, key.high, seen)
if err != nil {
h.logger.Error("Failed to record peering",
"as_a", key.low,
@@ -234,6 +267,10 @@ func (h *PeeringHandler) processPeerings() {
}
}
h.mu.Lock()
h.writing = 0
h.mu.Unlock()
h.logger.Info("Processed AS peerings",
"paths", len(paths),
"unique_peerings", len(peerings),
@@ -31,12 +31,14 @@ type recordingStore struct {
calls int
}
func (r *recordingStore) RecordPeering(asA, asB int, ts time.Time) error {
func (r *recordingStore) RecordPeering(
asA, asB int, seen database.SeenTimes,
) error {
r.mu.Lock()
r.calls++
r.mu.Unlock()
return r.mockStore.RecordPeering(asA, asB, ts)
return r.mockStore.RecordPeering(asA, asB, seen)
}
func (r *recordingStore) callCount() int {
@@ -52,8 +54,7 @@ func newTestHandler(db database.Store) *PeeringHandler {
return &PeeringHandler{
db: db,
logger: logger.New(),
asPaths: make(map[string]time.Time),
stopCh: make(chan struct{}),
asPaths: make(map[string]database.SeenTimes),
}
}
@@ -152,6 +153,43 @@ func TestPeeringHandlerLeavesATrailingASSetOutOfThePeerings(t *testing.T) {
}
}
// TestPeeringHandlerRecordsNothingFromAPathWithASZero handles AS paths that
// hold AS 0. RFC 7607 makes such a path malformed, so no peering is recorded
// from it, not even one between two other ASes of the path.
func TestPeeringHandlerRecordsNothingFromAPathWithASZero(t *testing.T) {
t.Parallel()
tests := []struct {
name string
path []any
}{
{name: "AS 0 between two ASes", path: []any{testASNA, 0, testASNB}},
{
name: "AS 0 after two ASes",
path: []any{testASNA, testASNB, 0, testASNC},
},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
t.Parallel()
store := newMockStore()
h := newTestHandler(store)
h.HandleMessage(&ristypes.RISMessage{
Path: decodePath(t, tt.path...),
ParsedTimestamp: time.Now().UTC(),
})
h.ProcessPeeringsNow()
if len(store.Peerings) > 0 {
t.Errorf("peerings recorded = %v, want none",
slices.Sorted(maps.Keys(store.Peerings)))
}
})
}
}
// TestPeeringHandlerProcessesEachRunAndEmpties verifies that a processing run
// empties the path map (the swap) and that a path seen again after a run is
// recorded in the next run too.
@@ -197,7 +235,7 @@ func TestPeeringHandlerStopWritesTheRemainingPaths(t *testing.T) {
h := NewPeeringHandler(store, logger.New())
handle(h, time.Now().UTC(), testASNA, testASNB)
h.Stop()
h.Stop(t.Context())
if got := store.callCount(); got != 1 {
t.Errorf("want 1 RecordPeering call when Stop returns, got %d", got)
@@ -221,10 +259,10 @@ func TestPeeringHandlerCapDropsAndCounts(t *testing.T) {
existing := pathKey(t, testASNA, testASNB)
h.mu.Lock()
h.asPaths[existing] = now
h.asPaths[existing] = database.SeenTimes{First: now, Last: now}
for i := 0; len(h.asPaths) < maxTrackedPaths; i++ {
h.asPaths[strconv.Itoa(i)] = now
h.asPaths[strconv.Itoa(i)] = database.SeenTimes{First: now, Last: now}
}
h.mu.Unlock()
@@ -254,11 +292,83 @@ func TestPeeringHandlerCapDropsAndCounts(t *testing.T) {
}
h.mu.Lock()
gotTS := h.asPaths[existing]
gotSeen := h.asPaths[existing]
h.mu.Unlock()
if !gotTS.Equal(refreshed) {
t.Fatalf("existing path timestamp not refreshed: want %v, got %v",
refreshed, gotTS)
if !gotSeen.Last.Equal(refreshed) {
t.Fatalf("existing path last seen not refreshed: want %v, got %v",
refreshed, gotSeen.Last)
}
}
// TestPeeringHandlerRunResetsTheDroppedCount fills the map, has the handler
// drop one path, and runs the processing. The count of dropped paths is the
// run's own, so it is 0 again after the run.
func TestPeeringHandlerRunResetsTheDroppedCount(t *testing.T) {
t.Parallel()
h := newTestHandler(newMockStore())
now := time.Now().UTC()
// Paths of one AS carry no peering, so the run records nothing.
h.mu.Lock()
for asn := 1; len(h.asPaths) < maxTrackedPaths; asn++ {
h.asPaths[pathKey(t, asn)] = database.SeenTimes{First: now, Last: now}
}
h.mu.Unlock()
handle(h, now, testASNA, testASNB)
if _, dropped := snapshot(h); dropped != 1 {
t.Fatalf("want dropped count 1 with the map full, got %d", dropped)
}
h.ProcessPeeringsNow()
if _, dropped := snapshot(h); dropped != 0 {
t.Errorf("want dropped count 0 after a run, got %d", dropped)
}
}
// TestPeeringHandlerStoresTheEarliestAndLatestTimesOfANewPeering handles two
// updates whose path carries a peering the database does not hold yet, the
// second 5 seconds after the first, in one run into a real database. The
// peering is stored first seen at the time of the first update and last seen
// at the time of the second.
func TestPeeringHandlerStoresTheEarliestAndLatestTimesOfANewPeering(
t *testing.T,
) {
t.Parallel()
db := newTestDatabase(t)
h := newTestHandler(db)
first := peerAnnouncement(testPeerIP, testV4Prefix)
second := peerAnnouncement(testPeerIP, testV4Prefix)
second.ParsedTimestamp = first.ParsedTimestamp.Add(secondUpdateAfter)
h.HandleMessage(first)
h.HandleMessage(second)
h.ProcessPeeringsNow()
peers, err := db.GetASPeers(testASNA)
if err != nil {
t.Fatalf("GetASPeers(%d): %v", testASNA, err)
}
if len(peers) != 1 || peers[0].ASN != testASNB {
t.Fatalf("peers of AS%d = %+v, want AS%d alone", testASNA, peers,
testASNB)
}
if !peers[0].FirstSeen.Equal(first.ParsedTimestamp) {
t.Errorf("first_seen of peering AS%d-AS%d = %s, want %s", testASNA,
testASNB, peers[0].FirstSeen, first.ParsedTimestamp)
}
if !peers[0].LastSeen.Equal(second.ParsedTimestamp) {
t.Errorf("last_seen of peering AS%d-AS%d = %s, want %s", testASNA,
testASNB, peers[0].LastSeen, second.ParsedTimestamp)
}
}
+96 -32
View File
@@ -1,6 +1,7 @@
package routewatch
import (
"context"
"net"
"net/netip"
"slices"
@@ -43,16 +44,17 @@ const (
)
// PrefixHandler tracks BGP prefixes and maintains a live routing table in the
// database. Routes are added on announcement and deleted on withdrawal, and all
// routes of a peer are deleted when its BGP session goes down.
// database. Routes are added on announcement and deleted on withdrawal or on an
// announcement whose AS path is empty or holds AS 0 anywhere, and all routes of
// a peer are deleted when its BGP session goes down.
type PrefixHandler struct {
db database.Store
logger *logger.Logger
metrics *metrics.Tracker
// Batching. mu guards batch, held and peersDown only: the flush goroutine
// takes them under mu and writes them after releasing mu, so
// HandleMessage waits for a database write only while batch is at
// Batching. mu guards batch, held, peersDown, writing and deleting only:
// the flush goroutine takes them under mu and writes them after releasing
// mu, so HandleMessage waits for a database write only while batch is at
// prefixBatchMaxSize.
mu sync.Mutex
batch []prefixUpdate
@@ -66,13 +68,21 @@ type PrefixHandler struct {
// since the batch was taken, and those whose route delete failed in the
// last flush.
peersDown []string
// writing is how many updates the flush goroutine took and has not
// finished writing.
writing int
// deleting is how many peers from peersDown the flush goroutine took and
// has not yet deleted the routes of.
deleting int
// batchTaken is signalled when the flush goroutine takes batch; its L is
// &mu.
batchTaken sync.Cond
batchFullCh chan struct{} // wakes the flush goroutine when batch is full
lastFlush time.Time // used only by the flush goroutine
stopCh chan struct{}
wg sync.WaitGroup
// stopCh hands Stop's context to the flush goroutine. It holds one, so
// Stop does not wait for a write in progress to hand it over.
stopCh chan context.Context
done chan struct{} // closed when the flush goroutine returns
}
type prefixUpdate struct {
@@ -95,12 +105,12 @@ func NewPrefixHandler(db database.Store, logger *logger.Logger) *PrefixHandler {
batch: make([]prefixUpdate, 0, prefixBatchSize),
batchFullCh: make(chan struct{}, 1),
lastFlush: time.Now(),
stopCh: make(chan struct{}),
stopCh: make(chan context.Context, 1),
done: make(chan struct{}),
}
h.batchTaken.L = &h.mu
// Start the flush timer goroutine
h.wg.Add(1)
go h.flushLoop()
return h
@@ -202,10 +212,39 @@ func (h *PrefixHandler) HandleMessage(msg *ristypes.RISMessage) {
}
}
// Stop gracefully stops the handler and flushes remaining batches
func (h *PrefixHandler) Stop() {
close(h.stopCh)
h.wg.Wait()
// Stop stops the flush goroutine, which writes the updates and peer downs the
// handler holds before it returns, and waits for it until ctx ends. Once ctx
// has ended the flush goroutine skips that last write, and a write still
// running is lost when the process exits. A peer whose route delete fails in
// the last write is not retried either. Stop logs how many updates are not
// written and how many peer downs have not had their routes deleted.
func (h *PrefixHandler) Stop(ctx context.Context) {
h.stopCh <- ctx
select {
case <-h.done:
case <-ctx.Done():
}
h.mu.Lock()
unwritten := h.writing + len(h.batch) + len(h.held)
peersDown := h.deleting + len(h.peersDown)
h.mu.Unlock()
if unwritten == 0 && peersDown == 0 {
return
}
if ctx.Err() != nil {
h.logger.Error("Stop deadline passed before the prefix handler wrote "+
"its updates", "updates", unwritten, "peers_down", peersDown)
return
}
h.logger.Error("The prefix handler stopped without deleting the routes "+
"of peers whose session went down", "updates", unwritten,
"peers_down", peersDown)
}
// peerSessionDown notes that the peer's BGP session went down, so that the next
@@ -230,7 +269,7 @@ func (h *PrefixHandler) peerSessionDown(peer string) {
// flushLoop runs in a goroutine, the only one that writes the batch: it
// flushes when the batch is full, periodically, and once more on Stop.
func (h *PrefixHandler) flushLoop() {
defer h.wg.Done()
defer close(h.done)
ticker := time.NewTicker(prefixBatchTimeout)
defer ticker.Stop()
@@ -243,9 +282,11 @@ func (h *PrefixHandler) flushLoop() {
}
case <-h.batchFullCh:
h.flushBatch()
case <-h.stopCh:
// Final flush
h.flushBatch()
case ctx := <-h.stopCh:
// Final flush, unless the stop deadline has passed
if ctx.Err() == nil {
h.flushBatch()
}
return
}
@@ -254,7 +295,9 @@ func (h *PrefixHandler) flushLoop() {
// takeBatch returns the pending updates, the held ones first, and the peers in
// peersDown, and leaves an empty batch, no held updates and no peers in their
// place for HandleMessage to fill.
// place for HandleMessage to fill. The updates count in writing until
// flushBatch has written them, and the peers in deleting until their routes
// are deleted.
func (h *PrefixHandler) takeBatch() ([]prefixUpdate, []string) {
h.mu.Lock()
defer h.mu.Unlock()
@@ -268,6 +311,8 @@ func (h *PrefixHandler) takeBatch() ([]prefixUpdate, []string) {
batch = slices.Concat(h.held, h.batch)
}
h.writing = len(batch)
h.deleting = len(peersDown)
h.held = nil
h.batch = make([]prefixUpdate, 0, prefixBatchSize)
h.peersDown = nil
@@ -303,8 +348,19 @@ func (h *PrefixHandler) flushBatch() {
lastUpdates := make(map[prefixAndPeer]prefixUpdate)
// Each prefix the batch names, announced or withdrawn, with the earliest
// timestamp among all of its updates, not only each peer's last one: the
// prefix tables store only first_seen, written when the prefix is new and
// never changed after.
prefixesToUpdate := make(map[string]time.Time)
for _, update := range batch {
lastUpdates[prefixAndPeer{update.prefix, update.peer}] = update
seen, exists := prefixesToUpdate[update.prefix]
if !exists || update.timestamp.Before(seen) {
prefixesToUpdate[update.prefix] = update.timestamp
}
}
// Collect routes to upsert and delete
@@ -313,19 +369,14 @@ func (h *PrefixHandler) flushBatch() {
routesToDelete []database.LiveRouteDeletion
)
// Collect unique prefixes to update
prefixesToUpdate := make(map[string]time.Time)
for _, update := range lastUpdates {
// Track prefix for both announcements and withdrawals
seen, exists := prefixesToUpdate[update.prefix]
if !exists || update.timestamp.After(seen) {
prefixesToUpdate[update.prefix] = update.timestamp
}
// An announcement is stored when its path gives an origin, or when it
// ends in an AS set of several members: that route is stored with
// origin 0 (none). An announcement with an empty path is not stored.
// origin 0 (none). Any other update deletes the peer's route for the
// prefix: a withdrawal, or an announcement whose path is empty or
// holds AS 0 anywhere (the decoder empties such a path). Such an
// announcement replaces the peer's route, as any announcement does,
// with none (RFC 7607 treats AS 0 in a path as a withdrawal).
if update.messageType == "announcement" &&
(update.originASN > 0 || update.endsInSet) {
// Create live route for batch upsert
@@ -333,11 +384,11 @@ func (h *PrefixHandler) flushBatch() {
if route != nil {
routesToUpsert = append(routesToUpsert, route)
}
} else if update.messageType == "withdrawal" {
} else {
// Parse CIDR to get IP version
_, ipVersion, err := parseCIDR(update.prefix)
if err != nil {
h.logger.Error("Failed to parse CIDR for withdrawal",
h.logger.Error("Failed to parse CIDR for route deletion",
"prefix", update.prefix, "error", err)
continue
@@ -354,6 +405,10 @@ func (h *PrefixHandler) flushBatch() {
successCount := h.writeBatch(routesToUpsert, routesToDelete, prefixesToUpdate)
h.mu.Lock()
h.writing = 0
h.mu.Unlock()
elapsed := time.Since(startTime)
h.logger.Debug("Flushed prefix batch",
"batch_size", batchSize,
@@ -369,7 +424,8 @@ func (h *PrefixHandler) flushBatch() {
// deleteLiveRoutesOfPeers deletes all live routes of each of peers, the peers
// whose BGP session went down, and returns those whose delete failed. Most
// downs come from peers that have no routes, so only a delete that removed
// routes is logged.
// routes is logged. A peer whose delete succeeded no longer counts in deleting;
// a failed one counts until keepForNextFlush puts it back in peersDown.
func (h *PrefixHandler) deleteLiveRoutesOfPeers(peers []string) []string {
var failed []string
@@ -386,6 +442,10 @@ func (h *PrefixHandler) deleteLiveRoutesOfPeers(peers []string) []string {
continue
}
h.mu.Lock()
h.deleting--
h.mu.Unlock()
if deleted > 0 {
h.logger.Info(
"Deleted the live routes of a peer whose session went down",
@@ -439,8 +499,12 @@ func (h *PrefixHandler) keepForNextFlush(
kept = slices.Clone(kept[len(kept)-prefixBatchSize:])
}
// takeBatch left held empty, and only this flush fills it.
// takeBatch left held empty, and only this flush fills it. The kept
// updates now count in held, not in writing, and the failed peers in
// peersDown, not in deleting.
h.held = kept
h.writing = len(toWrite)
h.deleting = 0
for _, peer := range failedPeers {
if !slices.Contains(h.peersDown, peer) {
@@ -1,11 +1,13 @@
package routewatch
import (
"bytes"
"context"
"errors"
"fmt"
"net/netip"
"slices"
"strings"
"sync"
"testing"
"time"
@@ -24,6 +26,10 @@ const (
testV6Prefix = "2001:db8:1::/48"
)
// secondUpdateAfter is how long after the first update the tests of first_seen
// and last_seen send the second, in the same batch.
const secondUpdateAfter = 5 * time.Second
// TestPrefixHandlerStoresPrefixesTheIPLookupFinds runs announcements and
// withdrawals through the prefix handler into a real database and looks the
// addresses up. The prefixes are written the way the feed sends them: IPv6
@@ -81,6 +87,49 @@ func TestPrefixHandlerStoresPrefixesTheIPLookupFinds(t *testing.T) {
}
}
// TestPrefixHandlerStoresANewPrefixFirstSeenAtItsEarliestUpdate announces a
// prefix the database does not hold yet twice in one batch, the second time 5
// seconds after the first, through the prefix handler into a real database. The
// prefix is stored first seen at the time of the first announcement, whether
// the two come from two peers or from one, and the IP lookup answers with that
// time.
func TestPrefixHandlerStoresANewPrefixFirstSeenAtItsEarliestUpdate(
t *testing.T,
) {
t.Parallel()
const otherPeerIP = "2001:db8:ffff::2"
tests := []struct {
name string
firstPeer, secondPeer string
}{
{name: "two peers", firstPeer: testPeerIP, secondPeer: otherPeerIP},
{name: "one peer", firstPeer: testPeerIP, secondPeer: testPeerIP},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
t.Parallel()
first := peerAnnouncement(tt.firstPeer, testV4Prefix)
second := peerAnnouncement(tt.secondPeer, testV4Prefix)
second.ParsedTimestamp = first.ParsedTimestamp.Add(secondUpdateAfter)
db := handleBatches(t, [][]*ristypes.RISMessage{{first, second}})
info, err := db.GetIPInfo("192.0.2.1")
if err != nil {
t.Fatalf("GetIPInfo(192.0.2.1): %v", err)
}
if !info.FirstSeen.Equal(first.ParsedTimestamp) {
t.Errorf("first_seen of %s = %s, want %s", testV4Prefix,
info.FirstSeen, first.ParsedTimestamp)
}
})
}
}
// TestPrefixHandlerAppliesEachPeersLastUpdateInABatch runs updates for one
// prefix through the prefix handler into a real database. All updates carry the
// same timestamp, as updates within one second of the feed do. Within a batch,
@@ -329,6 +378,133 @@ func TestPrefixHandlerDoesNotStoreAnAnnouncementWithAnEmptyPath(t *testing.T) {
assertPeers(t, db, map[string][]string{testV4Prefix: nil})
}
// TestPrefixHandlerRemovesTheRouteOnAnAnnouncementWithoutAnOrigin runs, through
// the prefix handler into a real database, a peer's announcement of a prefix
// with origin AS testASNB and then the peer's announcement of the prefix with
// an AS path that gives no origin: one whose last AS is 0, an empty one, or one
// that holds AS 0 before its end, which decodes as an empty path. As any later
// announcement from the peer does, the second replaces the peer's route, here
// with none, whether it comes in a later batch or follows a withdrawal in one
// batch. The in-memory route count and prefix distribution must match the
// route table.
func TestPrefixHandlerRemovesTheRouteOnAnAnnouncementWithoutAnOrigin(
t *testing.T,
) {
t.Parallel()
const prefixMaskLength = 24
noOrigin := func(path ristypes.ASPath) *ristypes.RISMessage {
msg := peerAnnouncement(testPeerIP, testV4Prefix)
msg.Path = path
return msg
}
endsInZero := ristypes.ASPath{Sequence: []int{testASNA, 0}}
withdrawal := &ristypes.RISMessage{
Type: ristypes.MessageTypeUpdate,
Peer: testPeerIP,
ParsedTimestamp: time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC),
Withdrawals: []string{testV4Prefix},
}
tests := []struct {
name string
// Handled and flushed as one batch after the announcement with origin
// AS testASNB.
batch []*ristypes.RISMessage
}{
{
name: "a path whose last AS is 0",
batch: []*ristypes.RISMessage{noOrigin(endsInZero)},
},
{
name: "an empty path",
batch: []*ristypes.RISMessage{noOrigin(ristypes.ASPath{})},
},
{
name: "a path with AS 0 before its end",
batch: []*ristypes.RISMessage{
noOrigin(decodePath(t, testASNA, 0, testASNB)),
},
},
{
name: "a withdrawal and then a path whose last AS is 0",
batch: []*ristypes.RISMessage{withdrawal, noOrigin(endsInZero)},
},
}
for _, tt := range tests {
t.Run(tt.name, func(t *testing.T) {
t.Parallel()
db := handleBatches(t, [][]*ristypes.RISMessage{
{peerAnnouncement(testPeerIP, testV4Prefix)},
tt.batch,
})
checkLivePeers(t, db, testV4Prefix, prefixMaskLength, nil)
})
}
}
// TestPrefixHandlerDoesNotStoreAPrefixThatDoesNotParse runs an announcement of
// "not-a-prefix" and a withdrawal of "also/bad" through the prefix handler into
// a real database. Neither is stored in the prefix tables: the prefix count in
// the stats stays 0, both as kept in memory and as counted from the tables when
// the database is opened again.
func TestPrefixHandlerDoesNotStoreAPrefixThatDoesNotParse(t *testing.T) {
t.Parallel()
cfg := &config.Config{StateDir: t.TempDir()}
db, err := database.New(cfg, logger.New())
if err != nil {
t.Fatalf("failed to create database: %v", err)
}
// Built without NewPrefixHandler's flush timer, so the test flushes itself.
h := &PrefixHandler{db: db, logger: logger.New()}
withdrawal := &ristypes.RISMessage{
Type: ristypes.MessageTypeUpdate,
Peer: testPeerIP,
ParsedTimestamp: time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC),
Withdrawals: []string{"also/bad"},
}
h.HandleMessage(peerAnnouncement(testPeerIP, "not-a-prefix"))
h.HandleMessage(withdrawal)
h.flushBatch()
checkNoPrefixes := func(when string) {
t.Helper()
stats, err := db.GetStatsContext(context.Background())
if err != nil {
t.Fatalf("GetStatsContext %s: %v", when, err)
}
if stats.Prefixes != 0 {
t.Errorf("prefix count %s = %d, want 0", when, stats.Prefixes)
}
}
checkNoPrefixes("after the flush")
err = db.Close()
if err != nil {
t.Fatalf("Close: %v", err)
}
db, err = database.New(cfg, logger.New())
if err != nil {
t.Fatalf("failed to open the database again: %v", err)
}
t.Cleanup(func() { _ = db.Close() })
checkNoPrefixes("after opening the database again")
}
// TestStateMessagesGoToThePrefixHandlerNotThePeerHandler checks that STATE
// messages go to the prefix handler, which acts on a down, and not to the peer
// handler, which would record a peer whose session never comes up as active.
@@ -766,6 +942,53 @@ func TestPrefixHandlerKeepsAtMostABatchOfUpdatesWhileADeleteKeepsFailing(
}
}
// TestPrefixHandlerStopLogsAFailedDeleteWithoutTheDeadline stops a prefix
// handler, with no deadline, after a peer's session went down and the peer
// announced a prefix, into a database whose every delete of a peer's routes
// fails. Stop must log the peer down and the announcement as not written, and
// must not say that the stop deadline passed.
func TestPrefixHandlerStopLogsAFailedDeleteWithoutTheDeadline(t *testing.T) {
t.Parallel()
var logs bytes.Buffer
h := NewPrefixHandler(peerDeleteAlwaysFailsStore{Database: newTestDatabase(t)},
newErrorLogger(&logs))
h.HandleMessage(sessionDown())
h.HandleMessage(peerAnnouncement(testPeerIP, testV4Prefix))
h.Stop(t.Context())
logged := lastLogged(t, &logs)
if strings.Contains(logged.Msg, "deadline") {
t.Errorf("Stop logged %q although its deadline had not passed",
logged.Msg)
}
if logged.Updates != 1 || logged.PeersDown != 1 {
t.Errorf("Stop logged %d updates and %d peer downs not written, "+
"want 1 and 1", logged.Updates, logged.PeersDown)
}
}
// TestPrefixHandlerStopLogsNothingAfterADeleteThatSucceeds stops a prefix
// handler, with no deadline, after a peer's session went down, into a database
// whose delete of the peer's routes succeeds. Stop must log nothing: a peer
// whose routes are deleted no longer counts as a peer down left undone.
func TestPrefixHandlerStopLogsNothingAfterADeleteThatSucceeds(t *testing.T) {
t.Parallel()
var logs bytes.Buffer
h := NewPrefixHandler(newTestDatabase(t), newErrorLogger(&logs))
h.HandleMessage(sessionDown())
h.Stop(t.Context())
if logs.Len() != 0 {
t.Errorf("Stop logged %q after the routes of the peer whose session "+
"went down were deleted", logs.String())
}
}
// newTestDatabase opens a database in a new temporary directory. It is closed
// when the test ends.
func newTestDatabase(t *testing.T) *database.Database {
+180 -52
View File
@@ -31,6 +31,18 @@ const (
healthCheckTimeout = 2 * time.Second
)
// Limits of one IP lookup.
const (
// maxLookupTargets is the most addresses and host names an IP lookup may
// list, and the most addresses it may have once the names are resolved:
// each address costs up to 113 database reads and a PTR lookup.
maxLookupTargets = 10
// ptrLookupTimeout is each PTR lookup's own time limit, so that ten
// addresses whose PTR lookups never answer fit in the 30-second limit.
ptrLookupTimeout = 2 * time.Second
)
// Keys of the JSON envelope the handlers and middleware write, and the status
// value of an error answer.
const (
@@ -41,6 +53,15 @@ const (
jsonStatusError = "error"
)
// Error messages an answer sends, in place of the error behind it where there
// is one.
const (
invalidPrefixMessage = "Invalid prefix"
hostNotResolvedMessage = "could not resolve host name"
hostNotPublicMessage = "host name has no public address"
tooManyTargetsMessage = "Too many addresses or host names"
)
// IP versions as database.LiveRoute.IPVersion records them.
const (
ipVersionV4 = 4
@@ -68,7 +89,9 @@ func (s *Server) handleHealthCheck() http.HandlerFunc {
// Check database connectivity with lightweight ping
err := s.db.Ping(ctx)
if err != nil {
checks["database"] = "error: " + err.Error()
s.logger.Error("Health check database ping failed", "error", err)
checks["database"] = jsonStatusError
healthy = false
} else {
checks["database"] = "ok"
@@ -108,12 +131,12 @@ func (s *Server) handleHealthCheck() http.HandlerFunc {
// handleIndex returns a handler that serves the home page.
func (s *Server) handleIndex() http.HandlerFunc {
return func(w http.ResponseWriter, _ *http.Request) {
return func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "text/html; charset=utf-8")
tmpl := templates.IndexTemplate()
err := tmpl.Execute(w, nil)
err := tmpl.Execute(w, pageData{CSPNonce: cspNonce(r.Context())})
if err != nil {
s.logger.Error("Failed to render index template", "error", err)
http.Error(w, "Internal Server Error", http.StatusInternalServerError)
@@ -121,6 +144,12 @@ func (s *Server) handleIndex() http.HandlerFunc {
}
}
// pageData is what the pages that show no data are rendered with: the nonce
// their script and style blocks carry.
type pageData struct {
CSPNonce string
}
// writeJSONError writes a standardized JSON error response with the given
// status code and error message.
func (s *Server) writeJSONError(w http.ResponseWriter, statusCode int, message string) {
@@ -251,7 +280,7 @@ func (s *Server) handleStatusJSON() http.HandlerFunc {
if err != nil {
s.logger.Error("Failed to get database stats", "error", err)
s.writeJSONError(w, http.StatusInternalServerError, err.Error())
s.writeJSONError(w, http.StatusInternalServerError, internalErrorMessage)
return
}
@@ -541,7 +570,7 @@ func (s *Server) handleStats() http.HandlerFunc {
if err != nil {
s.logger.Error("Failed to get database stats", "error", err)
s.writeJSONError(w, http.StatusInternalServerError, err.Error())
s.writeJSONError(w, http.StatusInternalServerError, internalErrorMessage)
return
}
@@ -622,12 +651,12 @@ func (s *Server) statsResponse(
// handleStatusHTML returns a handler that serves the HTML status page,
// which displays real-time statistics fetched via JavaScript.
func (s *Server) handleStatusHTML() http.HandlerFunc {
return func(w http.ResponseWriter, _ *http.Request) {
return func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "text/html; charset=utf-8")
tmpl := templates.StatusTemplate()
err := tmpl.Execute(w, nil)
err := tmpl.Execute(w, pageData{CSPNonce: cspNonce(r.Context())})
if err != nil {
s.logger.Error("Failed to render template", "error", err)
http.Error(w, "Internal Server Error", http.StatusInternalServerError)
@@ -661,23 +690,26 @@ func (s *Server) handleIPInfo() http.HandlerFunc {
}
ctx := r.Context()
response := IPLookupResponse{
Query: target,
Results: make([]*database.IPInfo, 0),
}
response := IPLookupResponse{Query: target, Results: make([]*database.IPInfo, 0)}
// Collect all IPs to look up
ipsToLookup, resolveErrors := resolveLookupTargets(ctx, target)
ipsToLookup, resolveErrors, err := s.resolveLookupTargets(ctx, target)
if deadlinePassed(ctx) {
s.writeJSONError(w, http.StatusGatewayTimeout, requestTimeoutMessage)
return
}
if err != nil {
s.writeJSONError(w, http.StatusBadRequest, tooManyTargetsMessage)
return
}
response.Errors = append(response.Errors, resolveErrors...)
if len(ipsToLookup) == 0 {
s.writeJSONError(w, http.StatusBadRequest, "No valid IPs or hostnames provided")
s.writeJSONError(w, http.StatusBadRequest, noTargetsMessage(resolveErrors))
return
}
@@ -694,14 +726,20 @@ func (s *Server) handleIPInfo() http.HandlerFunc {
return
}
if err != nil {
switch {
case errors.Is(err, database.ErrNoRoute), errors.Is(err, database.ErrInvalidIP):
response.Errors = append(response.Errors, ip+": "+err.Error())
continue
case err != nil:
s.logger.Error("Failed to look up IP", "ip", ip, "error", err)
s.writeJSONError(w, http.StatusInternalServerError, internalErrorMessage)
return
}
// Do PTR lookup for this IP
ptrs := lookupPTRNames(ctx, ip)
ptrs := s.lookupPTRNames(ctx, ip)
if deadlinePassed(ctx) {
s.writeJSONError(w, http.StatusGatewayTimeout, requestTimeoutMessage)
@@ -722,17 +760,37 @@ func (s *Server) handleIPInfo() http.HandlerFunc {
// Queue WHOIS refresh for stale ASNs (non-blocking)
s.queueWHOISRefresh(refreshASNs)
// Return response (even if no results, include errors)
if len(response.Results) == 0 && len(response.Errors) > 0 {
s.writeJSONError(w, http.StatusNotFound, "No routes found: "+response.Errors[0])
s.writeIPLookupAnswer(w, response)
}
}
return
}
// noTargetsMessage returns the message of the 400 an IP lookup answers when
// no address is left to look up, followed by the first of resolveErrors, which
// says why, when there is one.
func noTargetsMessage(resolveErrors []string) string {
const message = "No valid IPs or hostnames provided"
err := writeJSONSuccess(w, response)
if err != nil {
s.logger.Error("Failed to encode IP lookup response", "error", err)
}
if len(resolveErrors) == 0 {
return message
}
return message + ": " + resolveErrors[0]
}
// writeIPLookupAnswer sends response, or 404 with its first error when no
// address had a route.
func (s *Server) writeIPLookupAnswer(
w http.ResponseWriter, response IPLookupResponse,
) {
if len(response.Results) == 0 && len(response.Errors) > 0 {
s.writeJSONError(w, http.StatusNotFound, "No routes found: "+response.Errors[0])
return
}
err := writeJSONSuccess(w, response)
if err != nil {
s.logger.Error("Failed to encode IP lookup response", "error", err)
}
}
@@ -764,12 +822,16 @@ func (s *Server) queueWHOISRefresh(asns map[int]bool) {
}
}
// resolveLookupTargets splits a comma-separated list of IP addresses and
// hostnames and returns the IP addresses to look up, resolving each hostname.
// A hostname that does not resolve is reported in the returned errors instead.
// It stops once ctx's deadline has passed; the caller then answers 504.
func resolveLookupTargets(ctx context.Context, target string) ([]string, []string) {
var ipsToLookup, resolveErrors []string
// errTooManyTargets is what resolveLookupTargets returns for a list of more
// than maxLookupTargets addresses and host names, or of names that resolve to
// more than maxLookupTargets addresses.
var errTooManyTargets = errors.New("too many addresses or host names")
// splitLookupTargets returns the addresses and host names in a comma-separated
// list, leaving out blank entries, or errTooManyTargets when there are more
// than maxLookupTargets.
func splitLookupTargets(target string) ([]string, error) {
var targets []string
for t := range strings.SplitSeq(target, ",") {
t = strings.TrimSpace(t)
@@ -777,6 +839,36 @@ func resolveLookupTargets(ctx context.Context, target string) ([]string, []strin
continue
}
if len(targets) == maxLookupTargets {
return nil, errTooManyTargets
}
targets = append(targets, t)
}
return targets, nil
}
// resolveLookupTargets splits a comma-separated list of IP addresses and
// hostnames and returns the IP addresses to look up, resolving each hostname.
// A hostname that does not resolve is reported in the returned errors instead,
// with the resolver's own error only in the log, since it names the DNS server.
// Only the public addresses a hostname resolves to are kept, so the answer
// does not show the deployment's private addresses; a hostname with none is
// reported in the errors. More than maxLookupTargets entries, or addresses once
// resolved, return errTooManyTargets. It stops once ctx's deadline has passed;
// the caller then answers 504.
func (s *Server) resolveLookupTargets(
ctx context.Context, target string,
) ([]string, []string, error) {
targets, err := splitLookupTargets(target)
if err != nil {
return nil, nil, err
}
var ipsToLookup, resolveErrors []string
for _, t := range targets {
// Check if this target is an IP address
if net.ParseIP(t) != nil {
ipsToLookup = append(ipsToLookup, t)
@@ -785,27 +877,57 @@ func resolveLookupTargets(ctx context.Context, target string) ([]string, []strin
}
// It's a hostname - resolve it
resolved, err := net.DefaultResolver.LookupHost(ctx, t)
resolved, err := s.resolver.LookupHost(ctx, t)
if deadlinePassed(ctx) {
return nil, nil
return nil, nil, nil
}
if err != nil {
resolveErrors = append(resolveErrors, t+": "+err.Error())
s.logger.Warn("Host name lookup failed", "host", t, "error", err)
resolveErrors = append(resolveErrors, t+": "+hostNotResolvedMessage)
continue
}
ipsToLookup = append(ipsToLookup, resolved...)
public := publicAddresses(resolved)
if len(public) == 0 {
resolveErrors = append(resolveErrors, t+": "+hostNotPublicMessage)
continue
}
ipsToLookup = append(ipsToLookup, public...)
}
return ipsToLookup, resolveErrors
if len(ipsToLookup) > maxLookupTargets {
return nil, nil, errTooManyTargets
}
return ipsToLookup, resolveErrors, nil
}
// publicAddresses returns the addresses in addrs that are global unicast and
// not private; Go counts the private ranges as global unicast.
func publicAddresses(addrs []string) []string {
var public []string
for _, a := range addrs {
ip, err := netip.ParseAddr(a)
if err == nil && ip.IsGlobalUnicast() && !ip.IsPrivate() {
public = append(public, a)
}
}
return public
}
// lookupPTRNames returns the PTR records of ip without their trailing dots, or
// nil when the lookup fails.
func lookupPTRNames(ctx context.Context, ip string) []string {
ptrs, err := net.DefaultResolver.LookupAddr(ctx, ip)
// nil when the lookup fails or runs past ptrLookupTimeout.
func (s *Server) lookupPTRNames(ctx context.Context, ip string) []string {
ctx, cancel := context.WithTimeout(ctx, ptrLookupTimeout)
defer cancel()
ptrs, err := s.resolver.LookupAddr(ctx, ip)
if err != nil {
return nil
}
@@ -819,7 +941,7 @@ func lookupPTRNames(ctx context.Context, ip string) []string {
}
// extractClientIP extracts the client IP from the request.
// Works with chi's RealIP middleware which sets RemoteAddr.
// Works with RealIPMiddleware, which sets RemoteAddr.
func extractClientIP(r *http.Request) string {
// RemoteAddr is in the form "IP:port" or just "IP" for unix sockets
host, _, err := net.SplitHostPort(r.RemoteAddr)
@@ -854,7 +976,9 @@ func (s *Server) handleASDetailJSON() http.HandlerFunc {
if errors.Is(err, database.ErrNoRoute) {
s.writeJSONError(w, http.StatusNotFound, err.Error())
} else {
s.writeJSONError(w, http.StatusInternalServerError, err.Error())
s.logger.Error("Failed to get AS details", "asn", asn, "error", err)
s.writeJSONError(w, http.StatusInternalServerError,
internalErrorMessage)
}
return
@@ -933,7 +1057,7 @@ func (s *Server) handlePrefixDetailJSON() http.HandlerFunc {
// tables store, so that any valid way of writing it finds the route.
parsed, err := netip.ParsePrefix(prefixParam + "/" + lenParam)
if err != nil {
s.writeJSONError(w, http.StatusBadRequest, err.Error())
s.writeJSONError(w, http.StatusBadRequest, invalidPrefixMessage)
return
}
@@ -951,7 +1075,10 @@ func (s *Server) handlePrefixDetailJSON() http.HandlerFunc {
if errors.Is(err, database.ErrNoRoute) {
s.writeJSONError(w, http.StatusNotFound, err.Error())
} else {
s.writeJSONError(w, http.StatusInternalServerError, err.Error())
s.logger.Error("Failed to get prefix details",
"prefix", prefix, "error", err)
s.writeJSONError(w, http.StatusInternalServerError,
internalErrorMessage)
}
return
@@ -1002,7 +1129,7 @@ func (s *Server) handleASDetail() http.HandlerFunc {
http.Error(w, "AS not found", http.StatusNotFound)
} else {
s.logger.Error("Failed to get AS details", "error", err)
http.Error(w, "Internal server error", http.StatusInternalServerError)
http.Error(w, internalErrorMessage, http.StatusInternalServerError)
}
return
@@ -1039,6 +1166,7 @@ func (s *Server) handleASDetail() http.HandlerFunc {
IPv6Count int
Peers []database.ASPeer
PeerCount int
CSPNonce string
}{
ASN: asInfo,
IPv4Prefixes: ipv4Prefixes,
@@ -1048,6 +1176,7 @@ func (s *Server) handleASDetail() http.HandlerFunc {
IPv6Count: len(ipv6Prefixes),
Peers: peers,
PeerCount: len(peers),
CSPNonce: cspNonce(r.Context()),
}
// Check if context is still valid before writing response
@@ -1058,9 +1187,7 @@ func (s *Server) handleASDetail() http.HandlerFunc {
w.Header().Set("Content-Type", "text/html; charset=utf-8")
tmpl := templates.ASDetailTemplate()
err = tmpl.Execute(w, data)
err = templates.ASDetailTemplate().Execute(w, data)
if err != nil {
s.logger.Error("Failed to render AS detail template", "error", err)
http.Error(w, "Internal Server Error", http.StatusInternalServerError)
@@ -1085,7 +1212,7 @@ func (s *Server) handlePrefixDetail() http.HandlerFunc {
// tables store, so that any valid way of writing it finds the route.
parsed, err := netip.ParsePrefix(prefixParam + "/" + lenParam)
if err != nil {
http.Error(w, "Invalid prefix", http.StatusBadRequest)
http.Error(w, invalidPrefixMessage, http.StatusBadRequest)
return
}
@@ -1104,7 +1231,7 @@ func (s *Server) handlePrefixDetail() http.HandlerFunc {
http.Error(w, "Prefix not found", http.StatusNotFound)
} else {
s.logger.Error("Failed to get prefix details", "error", err)
http.Error(w, "Internal server error", http.StatusInternalServerError)
http.Error(w, internalErrorMessage, http.StatusInternalServerError)
}
return
@@ -1131,6 +1258,7 @@ func (s *Server) handlePrefixDetail() http.HandlerFunc {
Origins []*ASNInfo
PeerCount int
OriginCount int
CSPNonce string
}{
Prefix: prefix,
MaskLength: maskLength,
@@ -1139,6 +1267,7 @@ func (s *Server) handlePrefixDetail() http.HandlerFunc {
Origins: origins,
PeerCount: len(routes),
OriginCount: len(origins),
CSPNonce: cspNonce(r.Context()),
}
// Check if context is still valid before writing response
@@ -1151,9 +1280,7 @@ func (s *Server) handlePrefixDetail() http.HandlerFunc {
w.Header().Set("Content-Type", "text/html; charset=utf-8")
tmpl := templates.PrefixDetailTemplate()
err = tmpl.Execute(w, data)
err = templates.PrefixDetailTemplate().Execute(w, data)
if err != nil {
s.logger.Error("Failed to render prefix detail template", "error", err)
http.Error(w, "Internal Server Error", http.StatusInternalServerError)
@@ -1303,7 +1430,7 @@ func (s *Server) prefixLengthHandler(ipVersion, maxMaskLength int) http.HandlerF
if err != nil {
s.logger.Error("Failed to get prefixes by length", "error", err)
http.Error(w, "Internal server error", http.StatusInternalServerError)
http.Error(w, internalErrorMessage, http.StatusInternalServerError)
return
}
@@ -1324,6 +1451,7 @@ func (s *Server) prefixLengthHandler(ipVersion, maxMaskLength int) http.HandlerF
"IPVersion": ipVersion,
"Prefixes": prefixesWithASDescriptions(prefixes),
"Count": len(prefixes),
"CSPNonce": cspNonce(r.Context()),
}
// Check if context is still valid before writing response
+416 -8
View File
@@ -9,7 +9,9 @@ import (
"net/http/httptest"
"runtime"
"slices"
"strconv"
"strings"
"sync/atomic"
"testing"
"time"
@@ -28,6 +30,14 @@ const (
testPeerV6 = "2001:db8::1"
)
// Paths several tests request.
const (
asPagePath = "/as/64500"
prefixLengthPagePath = "/prefixlength/24"
statusJSONPath = "/status.json"
statsPath = "/api/v1/stats"
)
// The names the stats handler tests report the two stats handlers by.
const (
statusJSONHandlerName = "status.json"
@@ -429,7 +439,7 @@ func TestPagesSayOriginZeroIsNoKnownOrigin(t *testing.T) {
s := New(db, streamer.New(logger.New(), metrics.New()), logger.New(), &config.Config{})
for _, path := range []string{"/prefix/" + testPrefixV4, "/prefixlength/24"} {
for _, path := range []string{"/prefix/" + testPrefixV4, prefixLengthPagePath} {
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
t.Context(), http.MethodGet, path, nil))
@@ -610,13 +620,13 @@ func TestRoutesAnswer504WhenDatabaseReadIsCutOff(t *testing.T) {
path string
wantJSONBody bool
}{
{path: "/as/64500"},
{path: asPagePath},
{path: "/prefix/192.0.2.0/24"},
{path: "/prefixlength/24"},
{path: prefixLengthPagePath},
{path: "/prefixlength6/48"},
{path: "/status.json", wantJSONBody: true},
{path: statusJSONPath, wantJSONBody: true},
{path: "/ip/192.0.2.1", wantJSONBody: true},
{path: "/api/v1/stats", wantJSONBody: true},
{path: statsPath, 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},
@@ -689,9 +699,9 @@ func TestRoutesAnswer504WhenSecondDatabaseReadIsCutOff(t *testing.T) {
path string
wantJSONBody bool
}{
{path: "/as/64500"},
{path: "/status.json", wantJSONBody: true},
{path: "/api/v1/stats", wantJSONBody: true},
{path: asPagePath},
{path: statusJSONPath, wantJSONBody: true},
{path: statsPath, wantJSONBody: true},
}
for _, tt := range tests {
@@ -758,6 +768,404 @@ func checkJSONErrorCode(
}
}
// errDiskIO is the database driver's error failingDB answers with.
var errDiskIO = errors.New("disk I/O error")
// failingDB embeds database.Store (left nil) and fails the reads of the JSON
// routes and the health check's ping with errDiskIO. Every other Store method
// is unused and would panic if called.
type failingDB struct {
database.Store
}
func (failingDB) Ping(_ context.Context) error {
return errDiskIO
}
func (failingDB) GetStatsContext(_ context.Context) (database.Stats, error) {
return database.Stats{}, errDiskIO
}
func (failingDB) GetIPInfoContext(
_ context.Context, _ string,
) (*database.IPInfo, error) {
return nil, errDiskIO
}
func (failingDB) GetASDetailsContext(
_ context.Context, _ int,
) (*database.ASN, []database.LiveRoute, error) {
return nil, nil, errDiskIO
}
func (failingDB) GetPrefixDetailsContext(
_ context.Context, _ string,
) ([]database.LiveRoute, map[int]database.ASN, error) {
return nil, nil, errDiskIO
}
// TestJSONRoutesDoNotSendErrorDetails sends a request to each JSON route and
// the health check with a store whose reads fail with the driver's error text,
// and a prefix that does not parse, and checks that no answer carries 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).
func TestJSONRoutesDoNotSendErrorDetails(t *testing.T) {
t.Parallel()
s := New(failingDB{}, streamer.New(logger.New(), metrics.New()), logger.New(),
&config.Config{})
tests := []struct {
path string
wantCode int
}{
{"/.well-known/healthcheck.json", http.StatusServiceUnavailable},
{statusJSONPath, http.StatusInternalServerError},
{statsPath, http.StatusInternalServerError},
{"/api/v1/as/64500", http.StatusInternalServerError},
{"/api/v1/prefix/192.0.2.0/24", http.StatusInternalServerError},
{"/api/v1/ip/192.0.2.1", http.StatusInternalServerError},
{"/api/v1/prefix/foo/24", http.StatusBadRequest},
}
for _, tt := range tests {
rec := httptest.NewRecorder()
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",
tt.path, rec.Code, tt.wantCode, rec.Body)
}
for _, detail := range []string{errDiskIO.Error(), "netip"} {
if strings.Contains(rec.Body.String(), detail) {
t.Errorf("%s: body %s carries the error text %q",
tt.path, rec.Body, detail)
}
}
}
}
// The addresses failingIPLookupDB fails the read of and finds a route for.
const (
failingLookupIP = "192.0.2.1"
routedLookupIP = "192.0.2.2"
)
// failingIPLookupDB embeds database.Store (left nil) and answers the IP lookup
// with errDiskIO for failingLookupIP, a route for routedLookupIP, and no route
// for any other address. Every other Store method is unused and would panic if
// called.
type failingIPLookupDB struct {
database.Store
}
func (failingIPLookupDB) GetIPInfoContext(
_ context.Context, ip string,
) (*database.IPInfo, error) {
switch ip {
case failingLookupIP:
return nil, errDiskIO
case routedLookupIP:
return &database.IPInfo{IP: ip}, nil
default:
return nil, database.ErrNoRoute
}
}
// TestIPLookupAnswers500WhenDatabaseReadFails sends IP lookups through the
// server's router with a store whose read of one address fails with the
// driver's error. A lookup that asks for that address answers 500 with the
// JSON error body, as the AS and prefix JSON routes do; an address with no
// route still answers 404. Before the fix the failed read was reported as if
// the address had no route: 404 for that address alone, and 200 beside a
// routed address (https://git.eeqj.de/sneak/routewatch/issues/109).
func TestIPLookupAnswers500WhenDatabaseReadFails(t *testing.T) {
t.Parallel()
s := New(failingIPLookupDB{}, streamer.New(logger.New(), metrics.New()),
logger.New(), &config.Config{})
tests := []struct {
path string
wantCode int
}{
{
path: "/api/v1/ip/" + failingLookupIP,
wantCode: http.StatusInternalServerError,
},
{
path: "/api/v1/ip/" + failingLookupIP + "," + routedLookupIP,
wantCode: http.StatusInternalServerError,
},
{
path: "/api/v1/ip/203.0.113.1",
wantCode: http.StatusNotFound,
},
}
for _, tt := range tests {
rec := httptest.NewRecorder()
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",
tt.path, rec.Code, tt.wantCode, rec.Body)
}
checkJSONErrorCode(t, tt.path, rec, tt.wantCode)
}
}
// errNoSuchHost is what fakeResolver answers a lookup it has no answer for
// with.
var errNoSuchHost = errors.New("no such host")
// fakeResolver answers a host name lookup with the addresses hosts lists for
// the name, and a PTR lookup with no names or, when ptrNeverAnswers is set,
// not at all: it waits until the lookup's context ends. hostLookups counts the
// host name lookups.
type fakeResolver struct {
hosts map[string][]string
ptrNeverAnswers bool
hostLookups atomic.Int64
}
func (r *fakeResolver) LookupHost(_ context.Context, host string) ([]string, error) {
r.hostLookups.Add(1)
addrs, ok := r.hosts[host]
if !ok {
return nil, errNoSuchHost
}
return addrs, nil
}
func (r *fakeResolver) LookupAddr(ctx context.Context, _ string) ([]string, error) {
if r.ptrNeverAnswers {
<-ctx.Done()
return nil, ctx.Err()
}
return nil, errNoSuchHost
}
// countingIPLookupDB embeds database.Store (left nil) and counts its IP
// lookups, answering each that the address has no route. Every other Store
// method is unused and would panic if called.
type countingIPLookupDB struct {
database.Store
lookups atomic.Int64
}
func (d *countingIPLookupDB) GetIPInfoContext(
_ context.Context, _ string,
) (*database.IPInfo, error) {
d.lookups.Add(1)
return nil, database.ErrNoRoute
}
// TestIPLookupRefusesTooManyAddresses sends IP lookups of maxLookupTargets
// addresses and of one more, listed or as a host name that resolves to them,
// and a lookup listing maxLookupTargets+1 host names. The longer lookups answer
// 400 without reading the database, and the list of host names without
// resolving any of them; the others read the database once per address. Before
// the fix every address was read and every name resolved, however many there
// were (https://git.eeqj.de/sneak/routewatch/issues/110).
func TestIPLookupRefusesTooManyAddresses(t *testing.T) {
t.Parallel()
addrs := make([]string, maxLookupTargets+1)
names := make([]string, maxLookupTargets+1)
for i := range addrs {
addrs[i] = "192.0.2." + strconv.Itoa(i+1)
names[i] = "host" + strconv.Itoa(i+1) + ".test"
}
hosts := map[string][]string{
"most.test": addrs[:maxLookupTargets],
"too-many.test": addrs,
}
tests := []struct {
target string
wantCode int
wantLookups int64
wantHostLookups int64
}{
{
strings.Join(addrs[:maxLookupTargets], ","),
http.StatusNotFound, maxLookupTargets, 0,
},
{strings.Join(addrs, ","), http.StatusBadRequest, 0, 0},
{"most.test", http.StatusNotFound, maxLookupTargets, 1},
{"too-many.test", http.StatusBadRequest, 0, 1},
{strings.Join(names, ","), http.StatusBadRequest, 0, 0},
}
for _, tt := range tests {
db := &countingIPLookupDB{}
s := New(db, streamer.New(logger.New(), metrics.New()), logger.New(),
&config.Config{})
resolver := &fakeResolver{hosts: hosts}
s.resolver = resolver
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
t.Context(), http.MethodGet, "/api/v1/ip/"+tt.target, nil))
if rec.Code != tt.wantCode {
t.Errorf("%s: status %d, want %d; body %s",
tt.target, rec.Code, tt.wantCode, rec.Body)
}
checkJSONErrorCode(t, tt.target, rec, tt.wantCode)
got := db.lookups.Load()
if got != tt.wantLookups {
t.Errorf("%s: %d database reads, want %d",
tt.target, got, tt.wantLookups)
}
gotHostLookups := resolver.hostLookups.Load()
if gotHostLookups != tt.wantHostLookups {
t.Errorf("%s: %d host name lookups, want %d",
tt.target, gotHostLookups, tt.wantHostLookups)
}
}
}
// addrInTestPrefixV4 is an address in testPrefixV4, which
// newServerWithTestRoutes stores a route for.
const addrInTestPrefixV4 = "192.0.2.1"
// TestIPLookupKeepsRouteWhenPTRLookupDoesNotAnswer looks up a routed address
// with a resolver that never answers its PTR lookup. Once the PTR lookup's own
// limit passes, the lookup answers 200 with the route. Before the fix the PTR
// lookup ran until the request's time limit, and the lookup answered 504
// without the route (https://git.eeqj.de/sneak/routewatch/issues/110).
func TestIPLookupKeepsRouteWhenPTRLookupDoesNotAnswer(t *testing.T) {
t.Parallel()
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)
defer cancel()
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
ctx, http.MethodGet, "/api/v1/ip/"+addrInTestPrefixV4, nil))
if rec.Code != http.StatusOK {
t.Fatalf("status %d, want %d; body %s", rec.Code, http.StatusOK, rec.Body)
}
var body struct {
Data IPLookupResponse `json:"data"`
}
err := json.Unmarshal(rec.Body.Bytes(), &body)
if err != nil {
t.Fatalf("decoding the answer %q: %v", rec.Body, err)
}
if len(body.Data.Results) != 1 || body.Data.Results[0].Netblock != testPrefixV4 {
t.Errorf("answer %s, want one result in %s", rec.Body, testPrefixV4)
}
}
// The host name TestIPLookupHidesPrivateAddresses resolves to a private
// address, and that address.
const (
internalHostName = "internal.test"
internalHostAddr = "10.0.0.5"
)
// TestIPLookupHidesPrivateAddresses looks up host names that resolve to a
// private address, alone or beside a routed address. No answer carries the
// private address, and a name with no other address is reported as having no
// public address, in the 400 when nothing else is left to look up. Before the
// fix the private address was looked up and named in the answer, "No routes
// found: 10.0.0.5: no route found for IP 10.0.0.5", so the API showed what the
// deployment's own DNS knows (https://git.eeqj.de/sneak/routewatch/issues/110).
func TestIPLookupHidesPrivateAddresses(t *testing.T) {
t.Parallel()
s := newServerWithTestRoutes(t)
s.resolver = &fakeResolver{hosts: map[string][]string{
internalHostName: {internalHostAddr},
"mixed.test": {internalHostAddr, addrInTestPrefixV4},
}}
notPublic := internalHostName + ": " + hostNotPublicMessage
tests := []struct {
target string
wantCode int
wantMessage string
wantErrors []string
}{
{
internalHostName, http.StatusBadRequest,
"No valid IPs or hostnames provided: " + notPublic, nil,
},
{
internalHostName + "," + addrInTestPrefixV4, http.StatusOK, "",
[]string{notPublic},
},
{"mixed.test", http.StatusOK, "", nil},
}
for _, tt := range tests {
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
t.Context(), http.MethodGet, "/api/v1/ip/"+tt.target, nil))
if rec.Code != tt.wantCode {
t.Errorf("%s: status %d, want %d; body %s",
tt.target, rec.Code, tt.wantCode, rec.Body)
}
if strings.Contains(rec.Body.String(), internalHostAddr) {
t.Errorf("%s: body %s carries %s", tt.target, rec.Body, internalHostAddr)
}
var body struct {
Data IPLookupResponse `json:"data"`
Error struct {
Msg string `json:"msg"`
} `json:"error"`
}
err := json.Unmarshal(rec.Body.Bytes(), &body)
if err != nil {
t.Errorf("%s: decoding the answer %q: %v", tt.target, rec.Body, err)
continue
}
if body.Error.Msg != tt.wantMessage {
t.Errorf("%s: error message %q, want %q",
tt.target, body.Error.Msg, tt.wantMessage)
}
if !slices.Equal(body.Data.Errors, tt.wantErrors) {
t.Errorf("%s: errors %q, want %q",
tt.target, body.Data.Errors, tt.wantErrors)
}
}
}
// settledGoroutineCount lets transient goroutines finish, then reports the
// current count.
func settledGoroutineCount() int {
+120 -4
View File
@@ -3,11 +3,15 @@ package server
import (
"bytes"
"context"
"crypto/rand"
"encoding/json"
"errors"
"fmt"
"log/slog"
"net/http"
"net/netip"
"slices"
"strings"
"sync"
"time"
@@ -118,6 +122,10 @@ func JSONResponseMiddleware(next http.Handler) http.Handler {
// requestTimeoutMessage is the error message sent with 504 Gateway Timeout.
const requestTimeoutMessage = "Request timeout"
// internalErrorMessage is the error message sent with 500 Internal Server
// Error, whatever went wrong; the handler logs the detail.
const internalErrorMessage = "Internal server error"
// deadlinePassed reports whether ctx ended because its deadline passed.
//
// A handler calls it right after each database read or host name lookup,
@@ -134,8 +142,9 @@ func deadlinePassed(ctx context.Context) bool {
//
// If a response is not valid JSON or is empty when JSON is expected, the middleware
// returns a properly formatted JSON error response. If the request's time limit
// has passed, it answers 504 with the error message "Request timeout". For other
// errors, it returns "Internal server error" with status 500 if the original
// has passed, it answers 504 with the error message "Request timeout". A 4xx
// keeps its status, with the status's standard text as the message. For other
// errors, it returns "Internal server error", with status 500 if the original
// status was 200.
//
// Non-JSON responses are passed through unchanged.
@@ -194,9 +203,14 @@ func JSONValidationMiddleware(next http.Handler) http.Handler {
w.WriteHeader(statusCode)
errorMsg := "Internal server error"
if statusCode == http.StatusGatewayTimeout {
errorMsg := internalErrorMessage
switch {
case statusCode == http.StatusGatewayTimeout:
errorMsg = requestTimeoutMessage
case statusCode >= http.StatusBadRequest &&
statusCode < http.StatusInternalServerError:
errorMsg = http.StatusText(statusCode)
}
response := map[string]any{
@@ -296,3 +310,105 @@ func DecodedPathMiddleware(next http.Handler) http.Handler {
next.ServeHTTP(w, r)
})
}
// The values of the headers SecurityHeadersMiddleware sets.
const (
// strictTransportSecurity tells browsers to reach this host and its
// subdomains only over HTTPS for a year. The server listens on plain
// HTTP behind a TLS-terminating proxy, which passes the header on.
strictTransportSecurity = "max-age=31536000; includeSubDomains"
// contentSecurityPolicy lets a page load content only from this server,
// and run or apply an inline script or style block only when the block
// carries the nonce made for that answer, which replaces %[1]s. No other
// site may frame the pages.
contentSecurityPolicy = "default-src 'self'; " +
"script-src 'nonce-%[1]s'; style-src 'nonce-%[1]s'; " +
"frame-ancestors 'none'; base-uri 'none'; form-action 'self'"
frameOptions = "DENY"
contentTypeOptions = "nosniff"
referrerPolicy = "strict-origin-when-cross-origin"
// permissionsPolicy turns off browser features the pages do not use.
permissionsPolicy = "accelerometer=(), camera=(), geolocation=(), " +
"gyroscope=(), magnetometer=(), microphone=(), payment=(), usb=()"
)
// cspNonceKey is the request context key of the nonce SecurityHeadersMiddleware
// made for the answer.
type cspNonceKey struct{}
// SecurityHeadersMiddleware sets the security headers REPO_POLICIES.md requires
// on every answer. Each answer's Content-Security-Policy names a nonce of its
// own; a page reads it with cspNonce and writes it on its script and style
// blocks.
func SecurityHeadersMiddleware(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
nonce := rand.Text()
header := w.Header()
header.Set("Strict-Transport-Security", strictTransportSecurity)
header.Set("Content-Security-Policy",
fmt.Sprintf(contentSecurityPolicy, nonce))
header.Set("X-Frame-Options", frameOptions)
header.Set("X-Content-Type-Options", contentTypeOptions)
header.Set("Referrer-Policy", referrerPolicy)
header.Set("Permissions-Policy", permissionsPolicy)
ctx := context.WithValue(r.Context(), cspNonceKey{}, nonce)
next.ServeHTTP(w, r.WithContext(ctx))
})
}
// cspNonce returns the nonce SecurityHeadersMiddleware made for the answer to
// the request with ctx.
func cspNonce(ctx context.Context) string {
nonce, _ := ctx.Value(cspNonceKey{}).(string)
return nonce
}
// RealIPMiddleware gives a request from one of trustedProxies the address of
// the client the proxies forwarded it for as its RemoteAddr: the last
// X-Forwarded-For entry that is not a trusted proxy. Each proxy appends the
// address it took the request from, so the entries left of that one are
// whatever the client sent. A request from any other peer keeps the peer's
// address, whatever headers it carries.
func RealIPMiddleware(trustedProxies []netip.Prefix) func(http.Handler) http.Handler {
isTrusted := func(addr netip.Addr) bool {
return slices.ContainsFunc(trustedProxies, func(proxy netip.Prefix) bool {
return proxy.Contains(addr.Unmap())
})
}
return func(next http.Handler) http.Handler {
return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
peer, err := netip.ParseAddrPort(r.RemoteAddr)
if err != nil || !isTrusted(peer.Addr()) {
next.ServeHTTP(w, r)
return
}
// A header sent on several lines is one list.
entries := strings.Split(
strings.Join(r.Header.Values("X-Forwarded-For"), ","), ",")
for _, entry := range slices.Backward(entries) {
addr, err := netip.ParseAddr(strings.TrimSpace(entry))
if err != nil {
break
}
r.RemoteAddr = addr.String()
if !isTrusted(addr) {
break
}
}
next.ServeHTTP(w, r)
})
}
}
+233
View File
@@ -0,0 +1,233 @@
package server
import (
"encoding/json"
"net/http"
"net/http/httptest"
"net/netip"
"strings"
"testing"
"time"
)
// The addresses the forwarding tests use: the client a proxy names in
// X-Forwarded-For, a peer inside the trusted range of
// TestRealIPMiddlewareTrustsOnlyConfiguredProxies, and a peer outside it,
// which lies in testPrefixV4 so that an IP lookup of it finds a route.
const (
forwardedClient = "203.0.113.9"
trustedPeer = "10.0.0.2:1234"
untrustedPeerAddr = "192.0.2.1"
untrustedPeer = untrustedPeerAddr + ":1234"
)
// TestResponsesCarrySecurityHeaders checks that a page, a JSON route and a
// path no route matches each answer with the security headers REPO_POLICIES.md
// requires, and that the Content-Security-Policy allows no inline content
// without a nonce (https://git.eeqj.de/sneak/routewatch/issues/108).
func TestResponsesCarrySecurityHeaders(t *testing.T) {
t.Parallel()
s := newServerWithTestRoutes(t)
headers := []string{
"Strict-Transport-Security",
"Content-Security-Policy",
"X-Frame-Options",
"X-Content-Type-Options",
"Referrer-Policy",
"Permissions-Policy",
}
for _, path := range []string{"/", statsPath, "/no-such-page"} {
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
t.Context(), http.MethodGet, path, nil))
for _, name := range headers {
if rec.Header().Get(name) == "" {
t.Errorf("%s: no %s header", path, name)
}
}
policy := rec.Header().Get("Content-Security-Policy")
if strings.Contains(policy, "'unsafe-") {
t.Errorf("%s: Content-Security-Policy %q allows unsafe content",
path, policy)
}
}
}
// TestJSONValidationKeeps4xxWithoutBody wraps a handler that answers 400
// without a body in JSONValidationMiddleware and checks that the JSON error
// body keeps the 400 and gives the status's own text. Before the fix it said
// "Internal server error"
// (https://git.eeqj.de/sneak/routewatch/issues/111).
func TestJSONValidationKeeps4xxWithoutBody(t *testing.T) {
t.Parallel()
handler := JSONValidationMiddleware(http.HandlerFunc(
func(w http.ResponseWriter, _ *http.Request) {
w.WriteHeader(http.StatusBadRequest)
}))
rec := httptest.NewRecorder()
handler.ServeHTTP(rec, httptest.NewRequestWithContext(
t.Context(), http.MethodGet, "/", nil))
const name = "400 without a body"
if rec.Code != http.StatusBadRequest {
t.Errorf("%s: status %d, want %d; body %s",
name, rec.Code, http.StatusBadRequest, rec.Body)
}
checkJSONErrorCode(t, name, rec, http.StatusBadRequest)
checkJSONErrorMessage(t, name, rec, http.StatusText(http.StatusBadRequest))
}
// TestPagesCarryTheCSPNonce checks that every script and style block of each
// page carries the nonce its Content-Security-Policy header names, so that the
// browser runs and applies them, that each answer has a nonce of its own, and
// that no page uses a style attribute, which the policy does not allow.
func TestPagesCarryTheCSPNonce(t *testing.T) {
t.Parallel()
s := newServerWithTestRoutes(t)
_, err := s.db.GetOrCreateASN(64500, time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC))
if err != nil {
t.Fatalf("GetOrCreateASN: %v", err)
}
paths := []string{
"/", "/status", asPagePath, "/prefix/" + testPrefixV4,
prefixLengthPagePath, "/prefixlength6/32",
}
seen := make(map[string]bool)
for _, path := range paths {
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
t.Context(), http.MethodGet, path, nil))
if rec.Code != http.StatusOK {
t.Errorf("%s: status %d, want %d; body %s",
path, rec.Code, http.StatusOK, rec.Body)
continue
}
policy := rec.Header().Get("Content-Security-Policy")
_, nonce, found := strings.Cut(policy, "'nonce-")
if !found {
t.Errorf("%s: Content-Security-Policy %q names no nonce", path, policy)
continue
}
nonce, _, _ = strings.Cut(nonce, "'")
if seen[nonce] {
t.Errorf("%s: nonce %q was already used for another answer", path, nonce)
}
seen[nonce] = true
page := rec.Body.String()
for _, tag := range []string{"<script", "<style"} {
withNonce := tag + ` nonce="` + nonce + `"`
if strings.Count(page, tag) != strings.Count(page, withNonce) {
t.Errorf("%s: a %s tag does not carry the nonce %q", path, tag, nonce)
}
}
if strings.Contains(page, "style=") {
t.Errorf("%s: the page uses a style attribute", path)
}
}
}
// TestForwardedForFromUntrustedPeerIsIgnored asks /ip/ for the caller's own
// address from a peer that is not a trusted proxy, with forwarding headers
// naming another address, and checks that the lookup is for the TCP peer.
// Before the fix any client could choose the address it was looked up and
// logged as (https://git.eeqj.de/sneak/routewatch/issues/108).
func TestForwardedForFromUntrustedPeerIsIgnored(t *testing.T) {
t.Parallel()
s := newServerWithTestRoutes(t)
req := httptest.NewRequestWithContext(t.Context(), http.MethodGet, "/ip/", nil)
req.RemoteAddr = untrustedPeer
req.Header.Set("X-Forwarded-For", forwardedClient)
req.Header.Set("X-Real-IP", forwardedClient)
req.Header.Set("True-Client-IP", forwardedClient)
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, req)
var body struct {
Data IPLookupResponse `json:"data"`
}
err := json.Unmarshal(rec.Body.Bytes(), &body)
if err != nil {
t.Fatalf("decoding the answer %q: %v", rec.Body, err)
}
if body.Data.Query != untrustedPeerAddr {
t.Errorf("looked up %q, want the TCP peer %s; answer %s",
body.Data.Query, untrustedPeerAddr, rec.Body)
}
}
// TestRealIPMiddlewareTrustsOnlyConfiguredProxies checks which address
// RealIPMiddleware gives a request: the TCP peer, unless the peer is a trusted
// proxy; then the last X-Forwarded-For entry that is not a trusted proxy,
// since the entries left of it are whatever the client sent.
func TestRealIPMiddlewareTrustsOnlyConfiguredProxies(t *testing.T) {
t.Parallel()
trusted := []netip.Prefix{netip.MustParsePrefix("10.0.0.0/8")}
tests := []struct {
name string
peer string
forwardedFor string
want string
}{
{"untrusted peer", untrustedPeer, forwardedClient, untrustedPeer},
{"trusted peer", trustedPeer, forwardedClient, forwardedClient},
{
"entries the client wrote", trustedPeer,
"198.51.100.7, " + forwardedClient, forwardedClient,
},
{
"two trusted proxies", trustedPeer,
forwardedClient + ", 10.0.0.3", forwardedClient,
},
{"no header", trustedPeer, "", trustedPeer},
{"entry not an address", trustedPeer, "client", trustedPeer},
}
for _, tt := range tests {
var got string
handler := RealIPMiddleware(trusted)(http.HandlerFunc(
func(_ http.ResponseWriter, r *http.Request) { got = r.RemoteAddr }))
req := httptest.NewRequestWithContext(t.Context(), http.MethodGet, "/", nil)
req.RemoteAddr = tt.peer
if tt.forwardedFor != "" {
req.Header.Set("X-Forwarded-For", tt.forwardedFor)
}
handler.ServeHTTP(httptest.NewRecorder(), req)
if got != tt.want {
t.Errorf("%s: RemoteAddr %q, want %q", tt.name, got, tt.want)
}
}
}
+36 -2
View File
@@ -1,20 +1,36 @@
package server
import (
"net/http"
"time"
"github.com/go-chi/chi/v5"
"github.com/go-chi/chi/v5/middleware"
)
// The error messages the JSON routes under /api/v1 and /ip answer with when no
// route matches the path, and when none takes the method.
const (
notFoundMessage = "Not found"
methodNotAllowedMessage = "Method not allowed"
// jsonRoutesAllow is the Allow header of their 405 answer: every one of
// them takes GET and HEAD, and no other method.
jsonRoutesAllow = "GET, HEAD"
)
// setupRoutes configures the HTTP routes
func (s *Server) setupRoutes() {
r := chi.NewRouter()
// Middleware
r.Use(DecodedPathMiddleware)
// GetHead serves HEAD with the GET handler. It looks the route up by the
// path DecodedPathMiddleware sets, so it comes after it.
r.Use(middleware.GetHead)
r.Use(SecurityHeadersMiddleware)
r.Use(middleware.RequestID)
r.Use(middleware.RealIP)
r.Use(RealIPMiddleware(s.trustedProxies))
r.Use(RequestLoggerMiddleware(s.logger.Logger)) // Structured request logging
r.Use(middleware.Recoverer)
r.Use(JSONResponseMiddleware)
@@ -39,16 +55,34 @@ func (s *Server) setupRoutes() {
r.Get("/prefixlength/{length}", s.handlePrefixLength())
r.Get("/prefixlength6/{length}", s.handlePrefixLength6())
// The JSON routes answer a path or method they do not take with the JSON
// error body, as they answer everything else.
jsonNotFound := func(w http.ResponseWriter, _ *http.Request) {
s.writeJSONError(w, http.StatusNotFound, notFoundMessage)
}
jsonMethodNotAllowed := func(w http.ResponseWriter, _ *http.Request) {
// chi's own 405 answer sets Allow; one set in its place must too.
w.Header().Set("Allow", jsonRoutesAllow)
s.writeJSONError(w, http.StatusMethodNotAllowed, methodNotAllowedMessage)
}
// IP info JSON endpoints (replaces old /ip redirect)
r.Route("/ip", func(r chi.Router) {
r.Use(JSONValidationMiddleware)
r.Get("/", s.handleIPInfo()) // Client IP
r.NotFound(jsonNotFound)
r.MethodNotAllowed(jsonMethodNotAllowed)
r.Get("/", s.handleIPInfo()) // Client IP
// GetHead does not reach this route: mounting the group registers
// /ip and /ip/ for every method, so HEAD arrives here as HEAD.
r.Head("/", s.handleIPInfo())
r.Get("/{addr}", s.handleIPInfo()) // Specified IP
})
// API routes
r.Route("/api/v1", func(r chi.Router) {
r.Use(JSONValidationMiddleware)
r.NotFound(jsonNotFound)
r.MethodNotAllowed(jsonMethodNotAllowed)
r.Get("/stats", s.handleStats())
r.Get("/ip/{ip}", s.handleIPLookup())
r.Get("/as/{asn}", s.handleASDetailJSON())
+100
View File
@@ -0,0 +1,100 @@
package server
import (
"encoding/json"
"net/http"
"net/http/httptest"
"testing"
)
// TestRoutesAnswerHEAD sends HEAD for a page and JSON routes through the
// server's router and checks that each answers as GET does. /ip and /ip/, the
// 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).
func TestRoutesAnswerHEAD(t *testing.T) {
t.Parallel()
s := newServerWithTestRoutes(t)
for _, path := range []string{"/", statsPath, "/ip", "/ip/"} {
rec := httptest.NewRecorder()
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",
path, rec.Code, http.StatusOK, rec.Body)
}
}
}
// TestJSONRoutesAnswerUnmatchedRequestsWithJSONErrors sends a method the JSON
// routes do not take, and a path none of them matches, to each group of JSON
// routes through the server's router. Each must answer with the JSON error
// body, and a 405 must name the methods the routes take in its Allow header.
// Before the fix a 405 said "Internal server error" and a 404 was chi's plain
// text answer (https://git.eeqj.de/sneak/routewatch/issues/111).
func TestJSONRoutesAnswerUnmatchedRequestsWithJSONErrors(t *testing.T) {
t.Parallel()
s := newServerWithTestRoutes(t)
tests := []struct {
method string
path string
wantCode int
wantMsg string
}{
{http.MethodPost, statsPath, http.StatusMethodNotAllowed, methodNotAllowedMessage},
{http.MethodPost, "/ip/", http.StatusMethodNotAllowed, methodNotAllowedMessage},
{http.MethodGet, "/api/v1/nothing", http.StatusNotFound, notFoundMessage},
{http.MethodGet, "/ip/192.0.2.1/nothing", http.StatusNotFound, notFoundMessage},
}
for _, tt := range tests {
name := tt.method + " " + tt.path
rec := httptest.NewRecorder()
s.router.ServeHTTP(rec, httptest.NewRequestWithContext(
t.Context(), tt.method, tt.path, nil))
if rec.Code != tt.wantCode {
t.Errorf("%s: status %d, want %d; body %s",
name, rec.Code, tt.wantCode, rec.Body)
}
checkJSONErrorCode(t, name, rec, tt.wantCode)
checkJSONErrorMessage(t, name, rec, tt.wantMsg)
allow := rec.Header().Get("Allow")
if tt.wantCode == http.StatusMethodNotAllowed && allow != jsonRoutesAllow {
t.Errorf("%s: Allow %q, want %q", name, allow, jsonRoutesAllow)
}
}
}
// checkJSONErrorMessage checks that rec holds the JSON error body with the
// given message.
func checkJSONErrorMessage(
t *testing.T, name string, rec *httptest.ResponseRecorder, want string,
) {
t.Helper()
var body struct {
Error struct {
Msg string `json:"msg"`
} `json:"error"`
}
err := json.Unmarshal(rec.Body.Bytes(), &body)
if err != nil {
t.Errorf("%s: decoding the answer %q: %v", name, rec.Body, err)
return
}
if body.Error.Msg != want {
t.Errorf("%s: error message %q, want %q", name, body.Error.Msg, want)
}
}
+33 -7
View File
@@ -7,6 +7,7 @@ import (
"fmt"
"net"
"net/http"
"net/netip"
"strconv"
"time"
@@ -31,6 +32,13 @@ type ASNFetcher interface {
GetStats() ASNFetcherStats
}
// dnsResolver looks up the addresses of host names and the names of addresses
// in DNS, as *net.Resolver does.
type dnsResolver interface {
LookupHost(ctx context.Context, host string) ([]string, error)
LookupAddr(ctx context.Context, addr string) ([]string, error)
}
// Server provides HTTP endpoints for status monitoring
type Server struct {
router *chi.Mux
@@ -40,6 +48,14 @@ type Server struct {
port int
srv *http.Server
asnFetcher ASNFetcher
// trustedProxies are the reverse proxies whose X-Forwarded-For header
// RealIPMiddleware believes
trustedProxies []netip.Prefix
// resolver makes the IP lookup's DNS lookups: net.DefaultResolver, or a
// fake in tests
resolver dnsResolver
}
// New creates a new HTTP server
@@ -50,10 +66,12 @@ func New(
cfg *config.Config,
) *Server {
s := &Server{
db: db,
streamer: streamer,
logger: logger,
port: cfg.Port,
db: db,
streamer: streamer,
logger: logger,
port: cfg.Port,
trustedProxies: cfg.TrustedProxies,
resolver: net.DefaultResolver,
}
s.setupRoutes()
@@ -103,7 +121,9 @@ func (s *Server) Start(ctx context.Context) error {
return nil
}
// Stop gracefully stops the HTTP server
// Stop stops the HTTP server. It waits, until ctx ends, for the requests in
// progress to finish, and then closes the connections of those still running
// and returns ctx's error.
func (s *Server) Stop(ctx context.Context) error {
if s.srv == nil {
return nil
@@ -111,10 +131,16 @@ func (s *Server) Stop(ctx context.Context) error {
s.logger.Info("Stopping HTTP server")
return s.srv.Shutdown(ctx)
err := s.srv.Shutdown(ctx)
if err != nil {
return errors.Join(err, s.srv.Close())
}
return nil
}
// SetASNFetcher sets the ASN WHOIS fetcher for on-demand lookups.
// SetASNFetcher sets the ASN WHOIS fetcher for on-demand lookups. Call it
// before Start: the handlers read the fetcher without a lock.
func (s *Server) SetASNFetcher(fetcher ASNFetcher) {
s.asnFetcher = fetcher
}
+92
View File
@@ -0,0 +1,92 @@
package server
import (
"context"
"net"
"net/http"
"testing"
"time"
"git.eeqj.de/sneak/routewatch/internal/logger"
)
// TestStopClosesTheConnectionOfARequestStillRunning serves a request whose
// handler does not return until the test ends, and stops the server with a
// deadline that passes while the request runs. The client must then see its
// connection closed. Before the fix Stop returned at the deadline and left the
// connection open until the handler returned.
func TestStopClosesTheConnectionOfARequestStillRunning(t *testing.T) {
t.Parallel()
const (
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
// readHeaderTimeout bounds the test server's read of the request
// header, as every http.Server must.
readHeaderTimeout = time.Second
)
release := make(chan struct{})
defer close(release)
started := make(chan struct{})
var listenConfig net.ListenConfig
listener, err := listenConfig.Listen(t.Context(), "tcp", "127.0.0.1:0")
if err != nil {
t.Fatalf("failed to open the test listener: %v", err)
}
s := &Server{logger: logger.New(), srv: &http.Server{
Handler: http.HandlerFunc(func(http.ResponseWriter, *http.Request) {
close(started)
<-release
}),
ReadHeaderTimeout: readHeaderTimeout,
}}
go func() { _ = s.srv.Serve(listener) }()
answered := make(chan error, 1)
go func() {
req, err := http.NewRequestWithContext(t.Context(), http.MethodGet,
"http://"+listener.Addr().String()+"/", nil)
if err != nil {
answered <- err
return
}
resp, err := http.DefaultClient.Do(req)
if err == nil {
_ = resp.Body.Close()
}
answered <- err
}()
select {
case <-started:
case <-time.After(waitTimeout):
t.Fatal("the request did not reach the handler")
}
ctx, cancel := context.WithTimeout(t.Context(), stopDeadline)
defer cancel()
_ = s.Stop(ctx)
select {
case err := <-answered:
if err == nil {
t.Error("the request still running at the deadline was answered")
}
case <-time.After(waitTimeout):
t.Fatal("the connection of the request still running at the " +
"deadline was open after Stop returned")
}
}
+42 -13
View File
@@ -106,12 +106,12 @@ type RawMessageHandler func(line string)
// handlerMetrics tracks performance metrics for a handler
type handlerMetrics struct {
processedCount uint64 // Total messages processed
droppedCount uint64 // Total messages dropped
droppedCount atomic.Uint64 // Total messages dropped; not under mu
totalTime time.Duration // Total processing time (for average calculation)
minTime time.Duration // Minimum processing time
maxTime time.Duration // Maximum processing time
queueHighWaterMark int // Maximum queue length seen
mu sync.Mutex // Protects the metrics
mu sync.Mutex // Protects the other metrics
}
// handlerInfo wraps a handler with its queue and metrics
@@ -253,9 +253,10 @@ func (s *Streamer) Start(ctx context.Context) error {
// Stop ends the stream and stops the handler workers. It returns once each
// worker has handed its handler every message left on its queue and then the
// STATE messages held for it (see queueMessage). This method is safe to call
// STATE messages held for it (see queueMessage), or once ctx ends, and then
// logs how many messages were not handed over. This method is safe to call
// multiple times.
func (s *Streamer) Stop() {
func (s *Streamer) Stop(ctx context.Context) {
s.mu.Lock()
if s.cancel == nil {
// Not started, or already stopped: closing the queues again would panic.
@@ -264,28 +265,56 @@ func (s *Streamer) Stop() {
return
}
// Once ctx is cancelled the read loop queues and holds nothing more (see
// dispatchMessage).
// Once the stream's context is cancelled the read loop queues and holds
// nothing more (see dispatchMessage).
s.cancel()
s.cancel = nil
notHandedOver := 0
for _, info := range s.handlers {
// The held messages came after everything on the queue. Each waits
// for the worker, which does not take s.mu, to make room.
for _, msg := range info.heldState {
info.queue <- msg
// for the worker, which does not take s.mu, to make room, until ctx
// ends.
for len(info.heldState) > 0 && ctx.Err() == nil {
select {
case info.queue <- info.heldState[0]:
info.heldState = info.heldState[1:]
case <-ctx.Done():
}
}
notHandedOver += len(info.heldState)
info.heldState = nil
// The worker returns once it has emptied the closed queue.
close(info.queue)
}
handlers := s.handlers
s.running = false
s.mu.Unlock()
s.metrics.SetConnected(false)
s.workers.Wait()
workersDone := make(chan struct{})
go func() {
s.workers.Wait()
close(workersDone)
}()
select {
case <-workersDone:
case <-ctx.Done():
for _, info := range handlers {
notHandedOver += len(info.queue)
}
}
if notHandedOver > 0 {
s.logger.Error("Stop deadline passed before the handlers took every "+
"message", "messages", notHandedOver)
}
}
// IsRunning reports whether the streamer is currently connected and processing
@@ -342,7 +371,7 @@ func (s *Streamer) GetHandlerStats() []HandlerStats {
QueueCapacity: cap(info.queue),
QueueHighWaterMark: info.metrics.queueHighWaterMark,
ProcessedCount: info.metrics.processedCount,
DroppedCount: info.metrics.droppedCount,
DroppedCount: info.metrics.droppedCount.Load(),
MinProcessTime: info.metrics.minTime,
MaxProcessTime: info.metrics.maxTime,
}
@@ -459,7 +488,7 @@ func (s *Streamer) logMetrics() {
"queue_len", len(info.queue),
"queue_cap", cap(info.queue),
"processed", info.metrics.processedCount,
"dropped", info.metrics.droppedCount,
"dropped", info.metrics.droppedCount.Load(),
"avg_time", avgTime,
"min_time", info.metrics.minTime,
"max_time", info.metrics.maxTime,
@@ -829,7 +858,7 @@ func (s *Streamer) dispatchMessage(
}
if !s.queueMessage(info, msg) {
atomic.AddUint64(&info.metrics.droppedCount, 1)
info.metrics.droppedCount.Add(1)
s.totalDropped.Add(1)
continue
+131 -4
View File
@@ -1,9 +1,12 @@
package streamer
import (
"bytes"
"context"
"encoding/json"
"errors"
"io"
"log/slog"
"net/http"
"net/http/httptest"
"runtime"
@@ -377,7 +380,7 @@ func TestStopQueuesTheHeldStateMessages(t *testing.T) {
stopped := make(chan struct{})
go func() {
s.Stop()
s.Stop(t.Context())
close(stopped)
}()
@@ -412,6 +415,68 @@ func TestStopQueuesTheHeldStateMessages(t *testing.T) {
}
}
// TestStopReturnsByItsDeadline stops a streamer whose handler has a full queue
// and a STATE message held for it, and a worker that stays busy until the test
// ends, as one does whose handler waits for a database write. Stop must return
// within its deadline plus a small margin instead of waiting for room on the
// queue and for the worker, and log as not handed over the held message and
// every message on the queue.
func TestStopReturnsByItsDeadline(t *testing.T) {
t.Parallel()
const (
deadline = 100 * time.Millisecond
margin = 2 * time.Second
)
var logs bytes.Buffer
s := newStreamerWithFullStateQueue("")
s.logger = &logger.Logger{Logger: slog.New(slog.NewJSONHandler(&logs,
&slog.HandlerOptions{Level: slog.LevelError}))}
s.handlers[0].heldState = []*ristypes.RISMessage{
{Type: ristypes.MessageTypeState},
}
wantNotHandedOver := 1 + len(s.handlers[0].queue)
// Stop cancels the stream Start would have started; there is none here.
s.cancel = func() {}
release := make(chan struct{})
defer close(release)
s.workers.Go(func() { <-release })
ctx, cancel := context.WithTimeout(t.Context(), deadline)
defer cancel()
stopped := make(chan struct{})
go func() {
s.Stop(ctx)
close(stopped)
}()
select {
case <-stopped:
case <-time.After(deadline + margin):
t.Fatalf("Stop did not return within %s of its deadline", margin)
}
var logged struct {
Messages int `json:"messages"`
}
err := json.Unmarshal(logs.Bytes(), &logged)
if err != nil {
t.Fatalf("want the error Stop logs, got %q: %v", logs.String(), err)
}
if logged.Messages != wantNotHandedOver {
t.Errorf("Stop logged %d messages not handed over, want %d",
logged.Messages, wantNotHandedOver)
}
}
// TestStopBeforeMessageReachesQueues stops the streamer after the read loop
// has checked for cancellation but before it hands the message to the handler
// queues. That is the gap a stop from another goroutine can land in, and it
@@ -429,7 +494,7 @@ func TestStopBeforeMessageReachesQueues(t *testing.T) {
s := New(logger.New(), metrics.New())
s.url = srv.URL
s.RegisterHandler(updateHandler{})
s.RegisterRawHandler(func(string) { s.Stop() })
s.RegisterRawHandler(func(string) { s.Stop(t.Context()) })
// Start would run the stream in the background, where the test cannot
// wait for it. Setting cancel as Start does lets Stop cancel the stream
@@ -443,7 +508,7 @@ func TestStopBeforeMessageReachesQueues(t *testing.T) {
}
// A second Stop must not close the queues again.
s.Stop()
s.Stop(t.Context())
}
// TestReconnectWhenStreamEnds has the server end the first response
@@ -556,6 +621,68 @@ func TestStreamReadsLongLine(t *testing.T) {
}
}
// blockedHandler wants UPDATE messages, has room on its queue for one, and
// does not return from HandleMessage until release is closed.
type blockedHandler struct {
release chan struct{}
}
func (blockedHandler) WantsMessage(messageType string) bool {
return messageType == ristypes.MessageTypeUpdate
}
func (blockedHandler) QueueCapacity() int { return 1 }
func (h blockedHandler) HandleMessage(*ristypes.RISMessage) { <-h.release }
// TestHandlerStatsReadWhileMessagesAreDropped has the server send a few UPDATE
// lines to a blockedHandler, so the read loop drops all but the one the
// handler holds and the one on its queue, while the test reads the handler's
// statistics. The drop count must reach the number dropped, and the race
// detector must find the count read and written safely.
func TestHandlerStatsReadWhileMessagesAreDropped(t *testing.T) {
t.Parallel()
const (
lines = 5
wantDropped = lines - 2
maxWait = 5 * time.Second
)
srv := httptest.NewServer(http.HandlerFunc(
func(w http.ResponseWriter, r *http.Request) {
_, _ = io.WriteString(w, strings.Repeat(updateLine, lines))
flush(w)
<-r.Context().Done()
}))
defer srv.Close()
s := New(logger.New(), metrics.New())
s.url = srv.URL
handler := blockedHandler{release: make(chan struct{})}
s.RegisterHandler(handler)
err := s.Start(t.Context())
if err != nil {
t.Fatalf("Start returned error: %v", err)
}
defer s.Stop(t.Context())
defer close(handler.release)
// The test polls instead of waiting for a signal from the read loop: a
// signal would order the drops before the reads here, and the race
// detector would have nothing to report.
deadline := time.Now().Add(maxWait)
for s.GetHandlerStats()[0].DroppedCount < wantDropped {
if time.Now().After(deadline) {
t.Fatalf("fewer than %d messages counted as dropped within %s",
wantDropped, maxWait)
}
}
}
// TestPeerCountCountsEveryPeerHeardFrom has the server send an UPDATE from
// stateDownPeer and a KEEPALIVE from another peer, with no OPEN from either,
// and then a message that ends stateDownPeer's session: a NOTIFICATION, or a
@@ -676,7 +803,7 @@ func checkReconnect(
if err != nil {
t.Fatalf("Start returned error: %v", err)
}
defer s.Stop()
defer s.Stop(t.Context())
select {
case <-handler.handled:
+1 -1
View File
@@ -4,7 +4,7 @@
<meta charset="UTF-8">
<meta name="viewport" content="width=device-width, initial-scale=1.0">
<title>AS{{.ASN.ASN}} - {{.ASN.Handle}} - RouteWatch</title>
<style>
<style nonce="{{.CSPNonce}}">
* {
box-sizing: border-box;
}
+11 -4
View File
@@ -4,7 +4,7 @@
<meta charset="UTF-8">
<meta name="viewport" content="width=device-width, initial-scale=1.0">
<title>RouteWatch - BGP Route Monitor</title>
<style>
<style nonce="{{.CSPNonce}}">
* {
box-sizing: border-box;
}
@@ -167,6 +167,13 @@
color: #95a5a6;
margin-top: 8px;
}
#asname-results p {
color: #7f8c8d;
margin-top: 12px;
}
#asname-results .search-message {
font-size: 13px;
}
/* IP Lookup result */
.ip-result {
@@ -329,7 +336,7 @@
<span><a href="{{appGitCommitURL}}">{{appGitRevision}}</a></span>
</footer>
<script>
<script nonce="{{.CSPNonce}}">
function formatNumber(num) {
if (num >= 1000000) {
return (num / 1000000).toFixed(1) + 'M';
@@ -387,7 +394,7 @@
if (!query) return;
const resultsDiv = document.getElementById('asname-results');
resultsDiv.innerHTML = '<p class="loading" style="color: #7f8c8d; margin-top: 12px;">Searching...</p>';
resultsDiv.innerHTML = '<p class="loading">Searching...</p>';
// Use a simple client-side search against the asinfo data
// For now, redirect to AS page if it looks like an ASN
@@ -397,7 +404,7 @@
}
// Show a message that server-side search is coming
resultsDiv.innerHTML = '<p style="color: #7f8c8d; margin-top: 12px; font-size: 13px;">AS name search coming soon. For now, try an AS number.</p>';
resultsDiv.innerHTML = '<p class="search-message">AS name search coming soon. For now, try an AS number.</p>';
});
// IP lookup
+6 -2
View File
@@ -4,7 +4,7 @@
<meta charset="UTF-8">
<meta name="viewport" content="width=device-width, initial-scale=1.0">
<title>{{.Prefix}} - RouteWatch</title>
<style>
<style nonce="{{.CSPNonce}}">
* {
box-sizing: border-box;
}
@@ -221,6 +221,10 @@
border-radius: 4px;
border: 1px solid #e0e0e0;
}
.origin-item .peer-count {
color: #7f8c8d;
margin-left: 10px;
}
.empty-state {
text-align: center;
padding: 40px;
@@ -288,7 +292,7 @@
{{else}}
No known origin
{{end}}
<span style="color: #7f8c8d; margin-left: 10px;">{{.PeerCount}} peer{{if ne .PeerCount 1}}s{{end}}</span>
<span class="peer-count">{{.PeerCount}} peer{{if ne .PeerCount 1}}s{{end}}</span>
</div>
{{end}}
</div>
+1 -1
View File
@@ -4,7 +4,7 @@
<meta charset="UTF-8">
<meta name="viewport" content="width=device-width, initial-scale=1.0">
<title>Prefixes with /{{ .MaskLength }} - RouteWatch</title>
<style>
<style nonce="{{.CSPNonce}}">
* {
box-sizing: border-box;
}
+5 -4
View File
@@ -4,7 +4,7 @@
<meta charset="UTF-8">
<meta name="viewport" content="width=device-width, initial-scale=1.0">
<title>RouteWatch Status</title>
<style>
<style nonce="{{.CSPNonce}}">
* {
box-sizing: border-box;
}
@@ -130,6 +130,7 @@
color: #ef4444;
}
.error {
display: none;
background: #fee;
color: #c00;
padding: 10px;
@@ -173,7 +174,7 @@
</nav>
<main class="main-content">
<div id="error" class="error" style="display: none;"></div>
<div id="error" class="error"></div>
<div class="status-grid">
<div class="status-card">
<h2>RouteWatch</h2>
@@ -383,8 +384,8 @@
<div id="handler-stats-container" class="status-grid">
<!-- Handler stats will be dynamically added here -->
</div>
<script>
<script nonce="{{.CSPNonce}}">
function formatBytes(bytes) {
if (bytes === 0) return '0 B';
const k = 1024;
+54
View File
@@ -0,0 +1,54 @@
package templates_test
import (
"bytes"
"html/template"
"strings"
"testing"
"git.eeqj.de/sneak/routewatch/internal/templates"
)
// TestFooterLicense renders the home and status pages and expects each footer
// to name the licence in LICENSE, MIT, and not WTFPL.
func TestFooterLicense(t *testing.T) {
t.Parallel()
const (
license = "MIT"
wrongLicense = "WTFPL"
)
pages := map[string]*template.Template{
"index": templates.IndexTemplate(),
"status": templates.StatusTemplate(),
}
for name, tmpl := range pages {
t.Run(name, func(t *testing.T) {
t.Parallel()
var page bytes.Buffer
err := tmpl.Execute(&page, struct{ CSPNonce string }{})
if err != nil {
t.Fatalf("rendering the page: %v", err)
}
_, footer, found := strings.Cut(page.String(), "<footer")
if !found {
t.Fatal("the page has no footer")
}
footer, _, _ = strings.Cut(footer, "</footer>")
if !strings.Contains(footer, license) {
t.Errorf("footer does not name %s: %q", license, footer)
}
if strings.Contains(footer, wrongLicense) {
t.Errorf("footer names %s: %q", wrongLicense, footer)
}
})
}
}
+2 -2
View File
@@ -19,8 +19,8 @@ const (
Author = "@sneak"
// AuthorURL is the author's website
AuthorURL = "https://sneak.berlin"
// License is the program license
License = "WTFPL"
// License is the program license, as LICENSE grants it
License = "MIT"
// RepoURL is the git repository URL
RepoURL = "https://git.eeqj.de/sneak/routewatch"
)