Record origin changes and show them on the prefix page (closes #161)
check / check (push) Successful in 1m3s

The routing table records a row each time a prefix and origin AS gets its first peer (announced) or loses its last (withdrawn), with the time and how many peers carry the prefix just after. The prefix handler writes the rows to a new origin_changes table, apart from routes. Every hour the database maintainer keeps each prefix's rows from the last 72 hours or its newest 500, whichever keeps more. The prefix page lists them newest first, at most 5,000.

At most 100,000 rows wait in memory to be written; past that the oldest are dropped and logged. A stop loses the rows past its last write.

Model: deepseek-v4-pro (implementation); opus-5-5 (commit message)
This commit was merged in pull request #231.
This commit is contained in:
clawbot committed 2026-11-05 06:57:41 +01:00
1 parent 15bf20a894
commit e58c6635e7
20 files changed
+1651 -88

No files matched your search

@@ -330,6 +330,23 @@ func (m *mockStore) ReadRouteTable(_ context.Context) (*routetable.Table, error)
return routetable.New(routetable.Params{}), nil
}
// WriteOriginChanges records nothing: the mock keeps no origin changes.
func (m *mockStore) WriteOriginChanges(_ []routetable.OriginChange) error {
return nil
}
// GetOriginChanges returns no origin changes.
func (m *mockStore) GetOriginChanges(
_ context.Context, _ netip.Prefix, _ int,
) ([]routetable.OriginChange, error) {
return nil, nil
}
// PruneOriginChanges does nothing.
func (m *mockStore) PruneOriginChanges(_ context.Context) error {
return nil
}
// GetOrCreateASNBatch mock implementation
func (m *mockStore) GetOrCreateASNBatch(asns map[int]database.SeenTimes) error {
m.mu.Lock()
+97 -12
View File
@@ -175,12 +175,13 @@ func (s *blockingStore) releaseWrites() {
//
//nolint:tagliatelle // field names are the keys the handlers log
type stopLog struct {
Msg string `json:"msg"`
Updates int `json:"updates"`
TableChanges int `json:"table_changes"`
HeldMessages int `json:"held_messages"`
Paths int `json:"paths"`
BatchEntries int `json:"batch_entries"`
Msg string `json:"msg"`
Updates int `json:"updates"`
TableChanges int `json:"table_changes"`
HeldMessages int `json:"held_messages"`
OriginChanges int `json:"origin_changes"`
Paths int `json:"paths"`
BatchEntries int `json:"batch_entries"`
}
// newErrorLogger returns a logger that writes only errors, as JSON lines, to
@@ -472,6 +473,42 @@ func (s tableWriteBlockingStore) WriteRouteChanges(
return s.mockStore.WriteRouteChanges(changes, newPeers)
}
// stopPrefixHandlerWithBlockedWrite stops the prefix handler, whose store
// holds the write that fill starts, after handing it the message extra, and
// returns what Stop logged. blocking is the store the write waits on; store is
// a blockingStore wrapped for the routing table's changes or the origin
// changes.
func stopPrefixHandlerWithBlockedWrite(
t *testing.T,
blocking *blockingStore,
store database.Store,
logs *bytes.Buffer,
fill, extra *ristypes.RISMessage,
) stopLog {
t.Helper()
h := NewPrefixHandler(store, newErrorLogger(logs),
routetable.New(routetable.Params{}))
stopWhileAWriteIsBlocked(t, blocking, h, h.done,
[]*ristypes.RISMessage{fill}, extra)
return lastLogged(t, logs)
}
// originChangesBlockingStore is a blockingStore whose writes of the origin
// changes also wait until the test calls releaseWrites.
type originChangesBlockingStore struct {
*blockingStore
}
func (s originChangesBlockingStore) WriteOriginChanges(
changes []routetable.OriginChange,
) error {
s.waitForRelease()
return s.mockStore.WriteOriginChanges(changes)
}
// TestPrefixHandlerStopCountsTheTableChangesOfAWriteInProgress holds the write
// of the routing table's changes that a full batch starts, then hands the
// prefix handler one more prefix and stops it with a deadline that passes
@@ -485,19 +522,67 @@ func TestPrefixHandlerStopCountsTheTableChangesOfAWriteInProgress(t *testing.T)
var logs bytes.Buffer
blocking := newBlockingStore()
h := NewPrefixHandler(tableWriteBlockingStore{blockingStore: blocking},
newErrorLogger(&logs), routetable.New(routetable.Params{}))
fill := slices.Repeat([]string{testV4Prefix}, prefixBatchSize)
stopWhileAWriteIsBlocked(t, blocking, h, h.done,
[]*ristypes.RISMessage{prefixAnnouncement(fill)},
prefixAnnouncement([]string{extraPrefix}))
logged := stopPrefixHandlerWithBlockedWrite(t, blocking,
tableWriteBlockingStore{blockingStore: blocking}, &logs,
prefixAnnouncement(fill), prefixAnnouncement([]string{extraPrefix}))
if logged := lastLogged(t, &logs); logged.TableChanges != 2 {
if logged.TableChanges != 2 {
t.Errorf("Stop logged %d table changes not written, want 2",
logged.TableChanges)
}
}
// TestPrefixHandlerStopCountsTheOriginChangesOfAWriteInProgress holds the
// write of the origin changes that a full batch starts, then hands the prefix
// handler one more prefix and stops it with a deadline that passes meanwhile.
// Stop must log as not written both the change the held write took and the one
// since.
func TestPrefixHandlerStopCountsTheOriginChangesOfAWriteInProgress(t *testing.T) {
t.Parallel()
const extraPrefix = "198.51.100.0/24"
var logs bytes.Buffer
blocking := newBlockingStore()
fill := slices.Repeat([]string{testV4Prefix}, prefixBatchSize)
logged := stopPrefixHandlerWithBlockedWrite(t, blocking,
originChangesBlockingStore{blockingStore: blocking}, &logs,
prefixAnnouncement(fill), prefixAnnouncement([]string{extraPrefix}))
if logged.OriginChanges != 2 {
t.Errorf("Stop logged %d origin changes not written, want 2",
logged.OriginChanges)
}
}
// TestPrefixHandlerStopCountsTheWaitingOriginChanges stops the prefix handler
// with a deadline that has already passed, so the flush goroutine skips its
// last write. The origin changes still waiting in the routing table are then
// not written, and Stop must log them.
func TestPrefixHandlerStopCountsTheWaitingOriginChanges(t *testing.T) {
t.Parallel()
var logs bytes.Buffer
store := newMockStore()
h := newPrefixHandler(store, newErrorLogger(&logs),
routetable.New(routetable.Params{}), longerThanAnyTest,
maxTableChangesPerWrite)
h.HandleMessage(peerAnnouncement(testPeerIP, testV4Prefix, testV6Prefix))
ctx, cancel := context.WithCancel(t.Context())
cancel()
h.Stop(ctx)
if logged := lastLogged(t, &logs); logged.OriginChanges != 2 {
t.Errorf("Stop logged %d origin changes not written, want 2",
logged.OriginChanges)
}
}
// TestASHandlerSkipsItsLastWriteAfterTheStopDeadline also checks what Stop
// logs: the asnBatchSize entries of the held write and the entry for testASNB,
// handled since, are not written.
+27
View File
@@ -25,6 +25,10 @@ const (
// analyzeInterval is how often to run ANALYZE.
analyzeInterval = 1 * time.Hour
// originChangesPruneInterval is how often to prune the origin_changes
// table.
originChangesPruneInterval = 1 * time.Hour
// checkpointTimeout is the max time for WAL checkpoint.
checkpointTimeout = 10 * time.Second
@@ -33,6 +37,9 @@ const (
// analyzeTimeout is the max time for ANALYZE.
analyzeTimeout = 5 * time.Minute
// originChangesPruneTimeout is the max time for the origin changes prune.
originChangesPruneTimeout = 5 * time.Minute
)
// checkpointIncompleteMessage is logged, at debug level like a completed
@@ -80,6 +87,7 @@ func (m *DBMaintainer) Start(ctx context.Context) {
"checkpoint_interval", checkpointInterval,
"vacuum_interval", vacuumInterval,
"analyze_interval", analyzeInterval,
"origin_changes_prune_interval", originChangesPruneInterval,
)
}
@@ -111,6 +119,9 @@ func (m *DBMaintainer) run(ctx context.Context) {
analyzeTimer := time.NewTimer(analyzeInterval)
defer analyzeTimer.Stop()
pruneTimer := time.NewTimer(originChangesPruneInterval)
defer pruneTimer.Stop()
for {
select {
case <-m.stopCh:
@@ -127,6 +138,10 @@ func (m *DBMaintainer) run(ctx context.Context) {
case <-analyzeTimer.C:
m.runAnalyze(ctx)
analyzeTimer.Reset(analyzeInterval)
case <-pruneTimer.C:
m.runPruneOriginChanges(ctx)
pruneTimer.Reset(originChangesPruneInterval)
}
}
}
@@ -175,6 +190,18 @@ func (m *DBMaintainer) runAnalyze(ctx context.Context) {
}
}
// runPruneOriginChanges prunes the origin_changes table.
func (m *DBMaintainer) runPruneOriginChanges(ctx context.Context) {
duration, err := runWithTimeout(ctx, originChangesPruneTimeout,
m.db.PruneOriginChanges)
if err != nil {
m.logger.Error("Origin changes prune failed", "error", err,
"duration", duration)
} else {
m.logger.Debug("Origin changes pruned", "duration", duration)
}
}
// runWithTimeout runs operation with a context that ends after timeout and
// returns how long it took and its error.
func runWithTimeout(
+77 -30
View File
@@ -48,6 +48,10 @@ const (
// going down changes are written in about a minute.
maxTableChangesPerWrite = 20000
// maxOriginChangesPerWrite is the most origin changes of the routing
// table that one flush writes; the rest wait for the next flushes.
maxOriginChangesPerWrite = 20000
// maxHeldBackMessages is the most messages the handler holds back from
// peers whose session went down. A peer's messages are held back from
// the moment its session goes down until peerDown has applied them. If
@@ -81,8 +85,8 @@ const (
// a time, and takes new messages in between. It holds back at most
// maxHeldBackMessages messages.
//
// Each flush writes the table's changes to the database. It also stores each
// prefix the updates name with the time it was first seen.
// Each flush writes the table's changes and origin changes to the database.
// It also stores each prefix the updates name with the time it was first seen.
type PrefixHandler struct {
db database.Store
logger *logger.Logger
@@ -95,11 +99,14 @@ type PrefixHandler struct {
// tableChangesPerWrite is maxTableChangesPerWrite, except in tests that
// give a smaller one.
tableChangesPerWrite int
// originChangesPerWrite is maxOriginChangesPerWrite, except in tests that
// give a smaller one.
originChangesPerWrite int
// Batching. mu guards batch, writing and writingTableChanges: 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
// batchMaxSize.
// Batching. mu guards batch, writing, writingTableChanges and
// writingOriginChanges: 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 batchMaxSize.
mu sync.Mutex
batch []seenPrefix
// writing is how many updates the flush goroutine took and has not
@@ -108,6 +115,9 @@ type PrefixHandler struct {
// writingTableChanges is how many changes the flush goroutine took from
// the routing table and has not finished writing.
writingTableChanges int
// writingOriginChanges is how many origin changes the flush goroutine
// took from the routing table and has not finished writing.
writingOriginChanges int
// batchTaken is signalled when the flush goroutine takes batch; its L is
// &mu.
batchTaken sync.Cond
@@ -190,17 +200,18 @@ func newPrefixHandler(
batchTimeout time.Duration, tableChangesPerWrite int,
) *PrefixHandler {
h := &PrefixHandler{
db: db,
logger: logger,
table: table,
batch: make([]seenPrefix, 0, prefixBatchSize),
batchMaxSize: prefixBatchMaxSize,
tableChangesPerWrite: tableChangesPerWrite,
batchFullCh: make(chan struct{}, 1),
stopCh: make(chan context.Context, 1),
done: make(chan struct{}),
heldBack: make(map[string][]*ristypes.RISMessage),
tablePeersDown: table.PeersDown,
db: db,
logger: logger,
table: table,
batch: make([]seenPrefix, 0, prefixBatchSize),
batchMaxSize: prefixBatchMaxSize,
tableChangesPerWrite: tableChangesPerWrite,
originChangesPerWrite: maxOriginChangesPerWrite,
batchFullCh: make(chan struct{}, 1),
stopCh: make(chan context.Context, 1),
done: make(chan struct{}),
heldBack: make(map[string][]*ristypes.RISMessage),
tablePeersDown: table.PeersDown,
}
h.batchTaken.L = &h.mu
h.heldTaken.L = &h.mu
@@ -268,13 +279,13 @@ func (h *PrefixHandler) HeldBackCount() int {
// back meanwhile to be applied. It gives up this wait once ctx ends. Then Stop
// stops the flush goroutine and waits for it until ctx ends. The flush
// goroutine makes one last flush before it returns. That flush writes at most
// tableChangesPerWrite of the routing table's changes, and the prefixes of the
// updates the handler holds. Once ctx has ended the flush goroutine skips that
// last flush, and a write still running is lost when the process exits. A
// failed write of the table's changes is not retried either. Stop logs how
// many updates and table changes are not written. It also logs how many
// held-back messages are not applied. The caller calls Stop once its last
// HandleMessage has returned.
// tableChangesPerWrite of the routing table's changes, originChangesPerWrite of
// its origin changes, and the prefixes of the updates the handler holds. Once
// ctx has ended the flush goroutine skips that last flush, and a write still
// running is lost when the process exits. A failed write of the table's
// changes is not retried either. Stop logs how many updates, table changes and
// origin changes are not written. It also logs how many held-back messages are
// not applied. The caller calls Stop once its last HandleMessage has returned.
func (h *PrefixHandler) Stop(ctx context.Context) {
peerDownsDone := make(chan struct{})
@@ -299,23 +310,25 @@ func (h *PrefixHandler) Stop(ctx context.Context) {
unwritten := h.writing + len(h.batch)
tableChanges := h.writingTableChanges + h.table.ChangeCount()
heldMessages := h.heldCount
originChanges := h.writingOriginChanges + h.table.OriginChangeCount()
h.mu.Unlock()
if unwritten == 0 && tableChanges == 0 && heldMessages == 0 {
if unwritten == 0 && tableChanges == 0 && heldMessages == 0 &&
originChanges == 0 {
return
}
if ctx.Err() != nil {
h.logger.Error("Stop deadline passed before the prefix handler wrote "+
"its updates", "updates", unwritten, "table_changes", tableChanges,
"held_messages", heldMessages)
"held_messages", heldMessages, "origin_changes", originChanges)
return
}
h.logger.Error("The prefix handler stopped before it wrote everything",
"updates", unwritten, "table_changes", tableChanges,
"held_messages", heldMessages)
"held_messages", heldMessages, "origin_changes", originChanges)
}
// applyMessage applies msg. The caller holds mu. A peer's session going down
@@ -502,11 +515,12 @@ func (h *PrefixHandler) takeBatch() []seenPrefix {
return batch
}
// flushBatch writes the routing table's changes, then takes the pending batch
// and stores the prefixes it names, without holding the mutex during the
// writes.
// flushBatch writes the routing table's changes and origin changes, then
// takes the pending batch and stores the prefixes it names, without holding
// the mutex during the writes.
func (h *PrefixHandler) flushBatch() {
h.writeTableChanges()
h.writeOriginChanges()
batch := h.takeBatch()
if len(batch) == 0 {
@@ -608,6 +622,39 @@ func (h *PrefixHandler) writeTableChanges() {
}
}
// writeOriginChanges writes at most originChangesPerWrite of the routing
// table's origin changes. When the write fails, they go back to the table, so
// that a later write writes them again. A dropped change is logged as a
// warning.
func (h *PrefixHandler) writeOriginChanges() {
h.mu.Lock()
changes, dropped := h.table.TakeOriginChanges(h.originChangesPerWrite)
h.writingOriginChanges = len(changes)
h.mu.Unlock()
if dropped > 0 {
h.logger.Warn("Origin changes dropped", "dropped", dropped)
}
if len(changes) == 0 {
return
}
err := h.db.WriteOriginChanges(changes)
h.mu.Lock()
defer h.mu.Unlock()
h.writingOriginChanges = 0
if err != nil {
h.logger.Error("Failed to write the origin changes; the next flush "+
"retries", "changes", len(changes), "error", err)
h.table.PutBackOriginChanges(changes)
}
}
// canonicalPrefix returns prefix in the text form net/netip prints, the form
// the prefix tables store and the IP lookup reads them in. The feed sends IPv6
// announcements compressed ("2001:db8::/32") but IPv6 withdrawals uncompressed
@@ -327,13 +327,14 @@ func prefixHandlerWithoutTimer(store database.Store) *PrefixHandler {
table := routetable.New(routetable.Params{})
return &PrefixHandler{
db: store,
logger: logger.New(),
table: table,
batchMaxSize: prefixBatchMaxSize,
tableChangesPerWrite: maxTableChangesPerWrite,
heldBack: make(map[string][]*ristypes.RISMessage),
tablePeersDown: table.PeersDown,
db: store,
logger: logger.New(),
table: table,
batchMaxSize: prefixBatchMaxSize,
tableChangesPerWrite: maxTableChangesPerWrite,
originChangesPerWrite: maxOriginChangesPerWrite,
heldBack: make(map[string][]*ristypes.RISMessage),
tablePeersDown: table.PeersDown,
}
}
@@ -0,0 +1,181 @@
package routewatch
import (
"bytes"
"encoding/json"
"errors"
"log/slog"
"net/netip"
"slices"
"testing"
"git.eeqj.de/sneak/routewatch/internal/database"
"git.eeqj.de/sneak/routewatch/internal/logger"
"git.eeqj.de/sneak/routewatch/internal/routetable"
)
// TestPrefixHandlerWritesOriginChanges hands a running prefix handler an
// announcement and flushes. The flush must write the origin change to the
// database.
func TestPrefixHandlerWritesOriginChanges(t *testing.T) {
t.Parallel()
db := newTestDatabase(t)
h := prefixHandlerWithoutTimer(db)
h.HandleMessage(peerAnnouncement(testPeerIP, testV4Prefix))
h.flushBatch()
got, err := db.GetOriginChanges(t.Context(),
netip.MustParsePrefix(testV4Prefix), 10)
if err != nil {
t.Fatalf("GetOriginChanges: %v", err)
}
if len(got) != 1 || !got[0].Announced || got[0].OriginASN != testASNB {
t.Errorf("GetOriginChanges = %+v, want one announced row for AS%d",
got, testASNB)
}
}
// errTestOriginChangeWrite is the error a test store's failing write of the
// origin changes returns.
var errTestOriginChangeWrite = errors.New(
"test: the write of the origin changes failed")
// originChangesFailsStore is a real database whose first write of the origin
// changes fails, writing nothing. writes counts the writes asked for.
type originChangesFailsStore struct {
*database.Database
writes int
}
func (s *originChangesFailsStore) WriteOriginChanges(
changes []routetable.OriginChange,
) error {
s.writes++
if s.writes == 1 {
return errTestOriginChangeWrite
}
return s.Database.WriteOriginChanges(changes)
}
// TestPrefixHandlerWritesAFailedOriginChangeWriteAgain runs two flushes into a
// database whose first write of the origin changes fails. The second write must
// hold the change of the first.
func TestPrefixHandlerWritesAFailedOriginChangeWriteAgain(t *testing.T) {
t.Parallel()
db := newTestDatabase(t)
store := &originChangesFailsStore{Database: db}
h := prefixHandlerWithoutTimer(store)
h.HandleMessage(peerAnnouncement(testPeerIP, testV4Prefix))
h.flushBatch()
h.flushBatch()
got, err := db.GetOriginChanges(t.Context(),
netip.MustParsePrefix(testV4Prefix), 10)
if err != nil {
t.Fatalf("GetOriginChanges: %v", err)
}
if len(got) != 1 || !got[0].Announced || got[0].OriginASN != testASNB {
t.Errorf("GetOriginChanges = %+v, want one announced row for AS%d",
got, testASNB)
}
}
// originChangesWriteSizesStore is a real database that records how many
// changes each write of the origin changes holds.
type originChangesWriteSizesStore struct {
*database.Database
counts []int
}
func (s *originChangesWriteSizesStore) WriteOriginChanges(
changes []routetable.OriginChange,
) error {
s.counts = append(s.counts, len(changes))
return s.Database.WriteOriginChanges(changes)
}
// TestPrefixHandlerWritesManyOriginChangesOverSeveralFlushes has more origin
// changes than one write takes, then flushes three times. The first write must
// hold one write's worth, the second the rest, and the third nothing. The
// handler's limit is small.
func TestPrefixHandlerWritesManyOriginChangesOverSeveralFlushes(t *testing.T) {
t.Parallel()
const perWrite = 10
db := newTestDatabase(t)
store := &originChangesWriteSizesStore{Database: db}
h := prefixHandlerWithoutTimer(store)
h.originChangesPerWrite = perWrite
announceManyPrefixes(h.table, perWrite*3/2)
h.flushBatch()
h.flushBatch()
h.flushBatch()
want := []int{perWrite, perWrite*3/2 - perWrite}
if !slices.Equal(store.counts, want) {
t.Errorf("WriteOriginChanges held %v changes, want %v", store.counts, want)
}
}
// TestPrefixHandlerLogsTheDroppedOriginChanges fills the routing table with
// one origin change more than it keeps, then flushes. The warning the flush
// logs must carry the dropped count.
func TestPrefixHandlerLogsTheDroppedOriginChanges(t *testing.T) {
t.Parallel()
var logs bytes.Buffer
db := newTestDatabase(t)
h := prefixHandlerWithoutTimer(db)
h.logger = &logger.Logger{
Logger: slog.New(slog.NewJSONHandler(&logs,
&slog.HandlerOptions{Level: slog.LevelWarn})),
}
announceManyPrefixes(h.table, routetable.MaxWaitingOriginChanges+1)
h.flushBatch()
var warning struct {
Msg string `json:"msg"`
Dropped *int `json:"dropped"`
}
found := false
for line := range bytes.SplitSeq(bytes.TrimSpace(logs.Bytes()), []byte("\n")) {
warning.Dropped = nil
err := json.Unmarshal(line, &warning)
if err != nil {
t.Fatalf("want a JSON log line, got %q: %v", line, err)
}
if warning.Msg != "Origin changes dropped" {
continue
}
found = true
if warning.Dropped == nil || *warning.Dropped != 1 {
t.Errorf("the warning's dropped = %v, want 1", warning.Dropped)
}
}
if !found {
t.Errorf("no warning logged the dropped origin changes")
}
}