Compare commits
1
Commits
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
28f60500cb |
+68
-171
@@ -81,23 +81,6 @@ 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
|
||||
@@ -129,12 +112,6 @@ 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")
|
||||
@@ -217,13 +194,6 @@ 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{},
|
||||
@@ -1703,8 +1673,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) {
|
||||
@@ -1731,27 +1702,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
|
||||
}
|
||||
@@ -2285,24 +2241,9 @@ func (d *Database) Analyze(ctx context.Context) error {
|
||||
return nil
|
||||
}
|
||||
|
||||
// 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.
|
||||
// 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.
|
||||
func (d *Database) Checkpoint(ctx context.Context) error {
|
||||
d.lock("Checkpoint")
|
||||
defer d.unlock()
|
||||
@@ -2312,32 +2253,11 @@ func (d *Database) Checkpoint(ctx context.Context) error {
|
||||
return fmt.Errorf("failed to checkpoint WAL: %w", err)
|
||||
}
|
||||
|
||||
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)
|
||||
_, err = d.writer.ExecContext(ctx, "PRAGMA wal_checkpoint(TRUNCATE)")
|
||||
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
|
||||
}
|
||||
|
||||
@@ -2353,50 +2273,6 @@ 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 (
|
||||
@@ -2562,66 +2438,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
|
||||
|
||||
@@ -8,9 +8,9 @@ import (
|
||||
"log/slog"
|
||||
"math/rand/v2"
|
||||
"net/netip"
|
||||
"os"
|
||||
"slices"
|
||||
"strconv"
|
||||
"strings"
|
||||
"sync"
|
||||
"testing"
|
||||
"time"
|
||||
@@ -68,15 +68,6 @@ 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.
|
||||
@@ -467,33 +458,6 @@ 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,
|
||||
@@ -836,218 +800,6 @@ 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()
|
||||
}
|
||||
|
||||
// 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.
|
||||
@@ -1463,6 +1215,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.
|
||||
@@ -1767,3 +1651,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)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@@ -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);
|
||||
|
||||
@@ -2,7 +2,6 @@ package routewatch
|
||||
|
||||
import (
|
||||
"context"
|
||||
"errors"
|
||||
"log/slog"
|
||||
"sync"
|
||||
"time"
|
||||
@@ -35,12 +34,6 @@ 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
|
||||
@@ -130,13 +123,9 @@ func (m *DBMaintainer) runCheckpoint(ctx context.Context) {
|
||||
duration, err := runWithTimeout(ctx, checkpointTimeout, m.db.Checkpoint)
|
||||
m.recordResult(&m.lastCheckpoint, &m.lastCheckpointError, &m.checkpointCount, err)
|
||||
|
||||
switch {
|
||||
case errors.Is(err, database.ErrCheckpointIncomplete):
|
||||
m.logger.Debug(checkpointIncompleteMessage,
|
||||
"error", err, "duration", duration)
|
||||
case err != nil:
|
||||
if err != nil {
|
||||
m.logger.Error("WAL checkpoint failed", "error", err, "duration", duration)
|
||||
default:
|
||||
} else {
|
||||
m.logger.Debug("WAL checkpoint completed", "duration", duration)
|
||||
}
|
||||
}
|
||||
|
||||
@@ -1,54 +0,0 @@
|
||||
package routewatch
|
||||
|
||||
import (
|
||||
"bytes"
|
||||
"context"
|
||||
"encoding/json"
|
||||
"log/slog"
|
||||
"testing"
|
||||
|
||||
"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)
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user