routewatch/internal/database/database_internal_test.go

package database

import (
	"bytes"
	"context"
	"database/sql"
	"encoding/json"
	"errors"
	"fmt"
	"log/slog"
	"net/netip"
	"os"
	"sync"
	"testing"
	"time"

	"git.eeqj.de/sneak/routewatch/internal/config"
	"git.eeqj.de/sneak/routewatch/internal/logger"
	"git.eeqj.de/sneak/routewatch/internal/ristypes"
	"git.eeqj.de/sneak/routewatch/internal/routetable"
	"git.eeqj.de/sneak/routewatch/pkg/asinfo"
)

// tempStoreMemory is the PRAGMA temp_store value meaning "hold temp B-trees in
// memory"; the DSN change must leave temp_store below this so they spill to disk.
const tempStoreMemory = 2

// autoVacuumIncremental is the PRAGMA auto_vacuum value meaning "incremental".
const autoVacuumIncremental = 2

// vacuumTestRoutes is how many rows of the routes table the vacuum test writes
// and then deletes, enough to leave many free pages in the file.
const vacuumTestRoutes = 2000

// heldConnections is how many pooled connections the pragma test holds open at
// once so each is a distinct SQLite connection that parsed the DSN.
const heldConnections = 5

// bytesPerKiB turns a cache_size in KiB into bytes.
const bytesPerKiB = 1024

// testPeerIP is the address of the BGP peer the peer write tests store.
const testPeerIP = "192.0.2.254"

// Parameters for the checkpoint-contention regression test.
const (
	// contentionIterations is how many batch writes race the checkpoint loop.
	contentionIterations = 400
	// contendedASNCount is the small set of ASNs the batches reuse, so most
	// batches update existing rows and exercise the read-before-write path.
	contendedASNCount = 16
	// asnSecondBand offsets a second ASN per batch so each batch writes more
	// than one row.
	asnSecondBand = 100
)

// Parameters for the tests of maintenance and the database lock.
const (
	// lockMessageBuffer is how many lock messages a test database's logger
	// holds before logging waits for the test to read them.
	lockMessageBuffer = 64
	// operationKey is the log attribute that names the operation taking the
	// lock.
	operationKey = "operation"
	// testBatchWrite is the operation name the tests take the lock under.
	testBatchWrite = "test batch write"
	// lockWaitTimeout is the context timeout of a maintenance call that the
	// tests let run out while it waits for the lock.
	lockWaitTimeout = time.Millisecond
	// lockTestASN is the AS the batch write in the lock tests stores.
	lockTestASN = 64500
	// lockTestPrefix is the prefix the batch writes in the checkpoint tests
	// store.
	lockTestPrefix = "192.0.2.0/24"
	// 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
)

// TestConnectionPoolPragmas holds several pooled connections open at once and
// checks each one carries the per-connection settings from the DSN, plus the
// process-wide heap limits, and sees the new file with auto_vacuum
// incremental.
func TestConnectionPoolPragmas(t *testing.T) {
	t.Parallel()

	cfg := &config.Config{StateDir: t.TempDir()}

	db, err := New(cfg, logger.New())
	if err != nil {
		t.Fatalf("failed to create database: %v", err)
	}
	defer func() { _ = db.Close() }()

	ctx := context.Background()

	// Hold distinct connections open simultaneously so the pool must open a new
	// one (each parsing the DSN) rather than hand back the same connection.
	conns := make([]*sql.Conn, 0, heldConnections)
	defer func() {
		for _, c := range conns {
			_ = c.Close()
		}
	}()

	for i := range heldConnections {
		c, err := db.db.Conn(ctx)
		if err != nil {
			t.Fatalf("failed to open connection %d: %v", i, err)
		}

		conns = append(conns, c)
	}

	for i, c := range conns {
		cacheSize := readPragma(ctx, t, c, i, "cache_size")
		if cacheSize != sqliteReadCacheSizeKiB {
			t.Errorf("conn %d: cache_size = %d, want %d",
				i, cacheSize, sqliteReadCacheSizeKiB)
		}

		busyTimeout := readPragma(ctx, t, c, i, "busy_timeout")
		if busyTimeout != sqliteBusyTimeoutMs {
			t.Errorf("conn %d: busy_timeout = %d, want %d",
				i, busyTimeout, sqliteBusyTimeoutMs)
		}

		tempStore := readPragma(ctx, t, c, i, "temp_store")
		if tempStore == tempStoreMemory {
			t.Errorf("conn %d: temp_store = %d, want anything but %d (MEMORY)",
				i, tempStore, tempStoreMemory)
		}

		softHeapLimit := readPragma(ctx, t, c, i, "soft_heap_limit")
		if softHeapLimit != sqliteSoftHeapLimitBytes {
			t.Errorf("conn %d: soft_heap_limit = %d, want %d",
				i, softHeapLimit, sqliteSoftHeapLimitBytes)
		}

		hardHeapLimit := readPragma(ctx, t, c, i, "hard_heap_limit")
		if hardHeapLimit != sqliteHardHeapLimitBytes {
			t.Errorf("conn %d: hard_heap_limit = %d, want %d",
				i, hardHeapLimit, sqliteHardHeapLimitBytes)
		}

		autoVacuum := readPragma(ctx, t, c, i, "auto_vacuum")
		if autoVacuum != autoVacuumIncremental {
			t.Errorf("conn %d: auto_vacuum = %d, want %d (incremental)",
				i, autoVacuum, autoVacuumIncremental)
		}
	}
}

// TestWritingConnectionCache checks that the connection kept for writing has
// the large cache, and that the soft heap limit is above the caches of all the
// connections together: SQLite shrinks the caches to stay under it.
func TestWritingConnectionCache(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()

	var writeCacheSize, readCacheSize, softHeapLimit int64

	err = db.writer.QueryRowContext(ctx, "PRAGMA cache_size").
		Scan(&writeCacheSize)
	if err != nil {
		t.Fatalf("failed to read the writing connection's cache_size: %v", err)
	}

	if writeCacheSize != sqliteWriteCacheSizeKiB {
		t.Errorf("writing connection: cache_size = %d, want %d",
			writeCacheSize, sqliteWriteCacheSizeKiB)
	}

	err = db.db.QueryRowContext(ctx, "PRAGMA cache_size").Scan(&readCacheSize)
	if err != nil {
		t.Fatalf("failed to read a reading connection's cache_size: %v", err)
	}

	err = db.db.QueryRowContext(ctx, "PRAGMA soft_heap_limit").
		Scan(&softHeapLimit)
	if err != nil {
		t.Fatalf("failed to read soft_heap_limit: %v", err)
	}

	cachesBytes := -bytesPerKiB * (writeCacheSize + (maxConns-1)*readCacheSize)
	if softHeapLimit <= cachesBytes {
		t.Errorf("soft_heap_limit = %d, not above the %d bytes of the caches",
			softHeapLimit, cachesBytes)
	}
}

// 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,
) int64 {
	t.Helper()

	var value int64

	err := c.QueryRowContext(ctx, "PRAGMA "+name).Scan(&value)
	if err != nil {
		t.Fatalf("conn %d: failed to read %s: %v", i, name, err)
	}

	return value
}

// TestVacuumReturnsFreePages checks that after the rows of the routes table
// are deleted from a new database, one Vacuum call returns every page they
// used. The deletes leave fewer free pages than the 1000 Vacuum frees per
// call, so none may remain. With auto_vacuum off (issue
// https://git.eeqj.de/sneak/routewatch/issues/43) the free pages stayed in the
// file, and with the PRAGMA run by ExecContext Vacuum freed only one page per
// call.
func TestVacuumReturnsFreePages(t *testing.T) {
	t.Parallel()

	cfg := &config.Config{StateDir: t.TempDir()}

	db, err := New(cfg, logger.New())
	if err != nil {
		t.Fatalf("failed to create database: %v", err)
	}
	defer func() { _ = db.Close() }()

	ctx := context.Background()
	table := routetable.New(routetable.Params{})

	for i := range vacuumTestRoutes {
		announceTo(table, fmt.Sprintf("10.%d.%d.0/24", i/256, i%256), asA, peerA, 0)
	}

	writeTableChanges(t, db, table)

	// The peer going down removes every prefix, and so every row.
	table.PeersDown([]string{peerA})
	writeTableChanges(t, db, table)

	var before int

	err = db.db.QueryRowContext(ctx, "PRAGMA freelist_count").Scan(&before)
	if err != nil {
		t.Fatalf("failed to read freelist_count: %v", err)
	}

	if before == 0 {
		t.Fatalf("no free pages after deleting %d rows", vacuumTestRoutes)
	}

	err = db.Vacuum(ctx)
	if err != nil {
		t.Fatalf("Vacuum failed: %v", err)
	}

	var after int

	err = db.db.QueryRowContext(ctx, "PRAGMA freelist_count").Scan(&after)
	if err != nil {
		t.Fatalf("failed to read freelist_count: %v", err)
	}

	if after != 0 {
		t.Errorf("free pages after Vacuum = %d of %d, want 0", after, before)
	}
}

// TestBatchWriteDuringCheckpoint runs checkpoints back to back while batch
// writes run and checks that every batch write succeeds: a checkpoint holds the
// database lock as a batch write does, and checkpoints must not keep batch
// writes from getting it.
func TestBatchWriteDuringCheckpoint(t *testing.T) {
	t.Parallel()

	cfg := &config.Config{StateDir: t.TempDir()}

	db, err := New(cfg, logger.New())
	if err != nil {
		t.Fatalf("failed to create database: %v", err)
	}
	defer func() { _ = db.Close() }()

	ctx, cancel := context.WithCancel(context.Background())

	var wg sync.WaitGroup

	wg.Go(func() {
		for {
			select {
			case <-ctx.Done():
				return
			default:
				_ = db.Checkpoint(ctx) // errors are the checkpoint's own to absorb
			}
		}
	})

	ts := time.Now().UTC()
	seen := SeenTimes{First: ts, Last: ts}

	for i := range contentionIterations {
		asns := map[int]SeenTimes{
			i % contendedASNCount:                   seen,
			(i % contendedASNCount) + asnSecondBand: seen,
		}

		err := db.GetOrCreateASNBatch(asns)
		if err != nil {
			cancel()
			wg.Wait()
			t.Fatalf("batch write failed under checkpoint contention: %v", err)
		}
	}

	cancel()
	wg.Wait()
}

// lockMessage is a debug message the database lock logged, and the name of the
// operation that logged it.
type lockMessage struct {
	text      string
	operation string
}

// lockMessages is a log handler that passes on each message the database lock
// logs. The lock tests read it to know that an operation waits for the lock or
// holds it, instead of guessing how long that takes.
type lockMessages chan lockMessage

// Enabled lets every message through, so the lock's debug messages arrive.
func (m lockMessages) Enabled(context.Context, slog.Level) bool { return true }

// Handle passes on a message that names an operation and drops the others.
func (m lockMessages) Handle(_ context.Context, record slog.Record) error {
	record.Attrs(func(attr slog.Attr) bool {
		if attr.Key != operationKey {
			return true
		}

		m <- lockMessage{text: record.Message, operation: attr.Value.String()}

		return false
	})

	return nil
}

// WithAttrs returns m: the tests need no attributes added.
func (m lockMessages) WithAttrs([]slog.Attr) slog.Handler { return m }

// WithGroup returns m: the tests need no groups.
func (m lockMessages) WithGroup(string) slog.Handler { return m }

// newDatabaseWithLockMessages opens a new database whose logger passes the lock's
// messages to the returned channel.
func newDatabaseWithLockMessages(t *testing.T) (*Database, lockMessages) {
	t.Helper()

	messages := make(lockMessages, lockMessageBuffer)
	cfg := &config.Config{StateDir: t.TempDir()}

	db, err := New(cfg, &logger.Logger{Logger: slog.New(messages)})
	if err != nil {
		t.Fatalf("failed to create database: %v", err)
	}

	t.Cleanup(func() { _ = db.Close() })

	return db, messages
}

// waitForLockMessage waits until operation logs text, and fails the test if
// returned delivers first: the call running operation returned without logging
// text.
func waitForLockMessage(
	t *testing.T,
	messages lockMessages,
	text, operation string,
	returned <-chan error,
) {
	t.Helper()

	for {
		select {
		case message := <-messages:
			if message.text == text && message.operation == operation {
				return
			}
		case err := <-returned:
			t.Fatalf("%s returned (error: %v) without logging %q",
				operation, err, text)
		}
	}
}

// TestVacuumWaitsForBatchWrite holds the database lock as a batch write does and
// checks that Vacuum waits for it and then succeeds. Vacuum ran without the
// lock, met the batch writes at SQLite's write lock and failed with "database
// is locked" (https://git.eeqj.de/sneak/routewatch/issues/94).
func TestVacuumWaitsForBatchWrite(t *testing.T) {
	t.Parallel()

	db, messages := newDatabaseWithLockMessages(t)

	db.lock(testBatchWrite)

	vacuumed := make(chan error, 1)

	go func() { vacuumed <- db.Vacuum(context.Background()) }()

	waitForLockMessage(t, messages, lockWaitMessage, "Vacuum", vacuumed)

	db.unlock()

	err := <-vacuumed
	if err != nil {
		t.Fatalf("Vacuum after the batch write: %v", err)
	}
}

// TestBatchWriteWaitsForAnalyze keeps Analyze waiting for SQLite's write lock,
// which another connection holds, and checks that a batch write started
// meanwhile waits for Analyze to give up the database lock, that both then
// succeed, and that Analyze stored statistics. ANALYZE ran without the database
// lock, and a batch write that waited longer than the busy timeout for it failed
// with "database is locked".
func TestBatchWriteWaitsForAnalyze(t *testing.T) {
	t.Parallel()

	db, messages := newDatabaseWithLockMessages(t)
	ctx := context.Background()
	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)
	if err != nil {
		t.Fatalf("failed to store an AS: %v", err)
	}

	// With _txlock=immediate this transaction takes SQLite's write lock at
	// BEGIN, so ANALYZE has to wait for it while Analyze holds the database lock.
	writer, err := db.db.BeginTx(ctx, nil)
	if err != nil {
		t.Fatalf("failed to begin the transaction ANALYZE waits for: %v", err)
	}

	defer func() { _ = writer.Rollback() }()

	analyzed := make(chan error, 1)

	go func() { analyzed <- db.Analyze(ctx) }()

	waitForLockMessage(t, messages, lockHeldMessage, "Analyze", analyzed)

	written := make(chan error, 1)

	go func() { written <- db.GetOrCreateASNBatch(asns) }()

	waitForLockMessage(t, messages, lockWaitMessage, "GetOrCreateASNBatch", written)

	err = writer.Rollback()
	if err != nil {
		t.Fatalf("failed to end the transaction ANALYZE waits for: %v", err)
	}

	err = <-analyzed
	if err != nil {
		t.Errorf("Analyze: %v", err)
	}

	err = <-written
	if err != nil {
		t.Errorf("batch write after Analyze: %v", err)
	}

	var statistics int

	err = db.db.QueryRowContext(ctx,
		"SELECT count(*) FROM sqlite_stat1 WHERE tbl = 'asns'").Scan(&statistics)
	if err != nil {
		t.Fatalf("failed to read the statistics: %v", err)
	}

	if statistics == 0 {
		t.Error("Analyze stored no statistics for the asns table")
	}
}

// TestCheckpointLockWaitEndsWithContext holds the database lock while the
// context of a waiting Checkpoint times out, and checks that Checkpoint then
// returns the context's error and leaves the lock free.
func TestCheckpointLockWaitEndsWithContext(t *testing.T) {
	t.Parallel()

	db, messages := newDatabaseWithLockMessages(t)

	db.lock(testBatchWrite)

	ctx, cancel := context.WithTimeout(context.Background(), lockWaitTimeout)
	defer cancel()

	checkpointed := make(chan error, 1)

	go func() { checkpointed <- db.Checkpoint(ctx) }()

	waitForLockMessage(t, messages, lockWaitMessage, "Checkpoint", checkpointed)
	<-ctx.Done()
	db.unlock()

	err := <-checkpointed
	if !errors.Is(err, context.DeadlineExceeded) {
		t.Fatalf("Checkpoint = %v, want %v", err, context.DeadlineExceeded)
	}

	if !db.mu.TryLock() {
		t.Fatal("Checkpoint kept the database lock after its context ended")
	}

	db.mu.Unlock()
}

// TestCheckpointDoesNotWaitForReader keeps a read transaction on prefixes_v4
// open while a prefix 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.UpdatePrefixesBatch(map[string]time.Time{"198.51.100.0/24": ts})
	if err != nil {
		t.Fatalf("failed to store the prefix 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 prefixes int

	err = reader.QueryRowContext(ctx,
		"SELECT count(*) FROM prefixes_v4").Scan(&prefixes)
	if err != nil {
		t.Fatalf("failed to read the prefixes: %v", err)
	}

	err = db.UpdatePrefixesBatch(map[string]time.Time{"203.0.113.0/24": ts})
	if err != nil {
		t.Fatalf("failed to store a prefix after the read: %v", err)
	}

	started := time.Now()
	checkpointed := make(chan error, 1)

	go func() { checkpointed <- db.Checkpoint(ctx) }()

	// A prefix write, not an AS write: the first new AS loads the embedded AS
	// names, which takes seconds under -race.
	written := make(chan error, 1)

	go func() {
		written <- db.UpdatePrefixesBatch(map[string]time.Time{lockTestPrefix: ts})
	}()

	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 prefixes int

	err = reader.QueryRowContext(ctx,
		"SELECT count(*) FROM prefixes_v4").Scan(&prefixes)
	if err != nil {
		t.Fatalf("failed to read the prefixes: %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.UpdatePrefixesBatch(
		map[string]time.Time{lockTestPrefix: 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 prefix,
// 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.UpdatePrefixesBatch(
		map[string]time.Time{lockTestPrefix: time.Now().UTC()})
	if err != nil {
		t.Fatalf("failed to store a prefix: %v", err)
	}

	walBytes := walFileSize(t, db)
	if walBytes == 0 {
		t.Fatal("WAL file empty after the prefix 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 prefix 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 prefixes int

	err = reader.QueryRowContext(ctx,
		"SELECT count(*) FROM prefixes_v4").Scan(&prefixes)
	if err != nil {
		t.Fatalf("failed to read the prefixes: %v", err)
	}

	err = db.UpdatePrefixesBatch(
		map[string]time.Time{lockTestPrefix: time.Now().UTC()})
	if err != nil {
		t.Fatalf("failed to store a prefix 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
}

// TestGetASReadsTheRecordOrTheBuiltInList asks GetAS for an AS the asns table
// holds, one only the AS info lookup holds, and one neither holds. The first
// gets its record's seen times, the second its handle and description from the
// lookup, and only the third is not known.
func TestGetASReadsTheRecordOrTheBuiltInList(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 (
		storedASN  = 64500      // a documentation AS, not in the lookup
		listedASN  = 15169      // in the lookup, not stored
		unknownASN = 4200000001 // in neither
	)

	ts := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)

	_, err = db.GetOrCreateASN(storedASN, ts)
	if err != nil {
		t.Fatalf("GetOrCreateASN: %v", err)
	}

	listed, ok := asinfo.Get(listedASN)
	if !ok {
		t.Fatalf("AS%d is not in the AS info data", listedASN)
	}

	tests := []struct {
		asn       int
		want      ASN
		wantKnown bool
	}{
		{storedASN, ASN{ASN: storedASN, FirstSeen: ts, LastSeen: ts}, true},
		{listedASN, ASN{
			ASN: listedASN, Handle: listed.Handle, Description: listed.Description,
		}, true},
		{unknownASN, ASN{ASN: unknownASN}, false},
	}

	for _, tt := range tests {
		got, known, err := db.GetAS(t.Context(), tt.asn)
		if err != nil {
			t.Errorf("GetAS(%d): %v", tt.asn, err)

			continue
		}

		if !got.FirstSeen.Equal(tt.want.FirstSeen) ||
			!got.LastSeen.Equal(tt.want.LastSeen) {
			t.Errorf("GetAS(%d) seen %v to %v, want %v to %v", tt.asn,
				got.FirstSeen, got.LastSeen, tt.want.FirstSeen, tt.want.LastSeen)
		}

		got.FirstSeen, got.LastSeen = tt.want.FirstSeen, tt.want.LastSeen
		if *got != tt.want || known != tt.wantKnown {
			t.Errorf("GetAS(%d) = %+v, known %t; want %+v, known %t",
				tt.asn, *got, known, tt.want, tt.wantKnown)
		}
	}
}

// TestGetLastSeenASes stores three ASes, each last seen at another time, and
// expects the one last seen most recently and the one last seen longest ago.
// An empty asns table gives neither.
func TestGetLastSeenASes(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() }()

	newest, oldest, err := db.GetLastSeenASes(t.Context())
	if err != nil || newest != nil || oldest != nil {
		t.Fatalf("GetLastSeenASes() on an empty table = %+v, %+v, %v; want "+
			"neither", newest, oldest, err)
	}

	const (
		newestASN = 13335
		middleASN = 15169
		oldestASN = 3
	)

	start := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)

	err = db.GetOrCreateASNBatch(map[int]SeenTimes{
		middleASN: {First: start, Last: start.Add(time.Hour)},
		newestASN: {First: start, Last: start.Add(2 * time.Hour)},
		oldestASN: {First: start, Last: start.Add(time.Minute)},
	})
	if err != nil {
		t.Fatalf("GetOrCreateASNBatch: %v", err)
	}

	newest, oldest, err = db.GetLastSeenASes(t.Context())
	if err != nil {
		t.Fatalf("GetLastSeenASes: %v", err)
	}

	listed, _ := asinfo.Get(newestASN)

	if newest == nil || newest.ASN != newestASN ||
		!newest.LastSeen.Equal(start.Add(2*time.Hour)) ||
		newest.Description != listed.Description {
		t.Errorf("newest = %+v, want AS%d (%s) last seen %v", newest, newestASN,
			listed.Description, start.Add(2*time.Hour))
	}

	if oldest == nil || oldest.ASN != oldestASN ||
		!oldest.LastSeen.Equal(start.Add(time.Minute)) {
		t.Errorf("oldest = %+v, want AS%d last seen %v", oldest, oldestASN,
			start.Add(time.Minute))
	}
}

// TestGetASWHOISReadsTheStoredDetails stores an AS with WHOIS details and asks
// GetASWHOIS for it and for an AS the asns table does not hold. The first gets
// its stored handle, description and details, and the time they were fetched.
// The second gets only its number, although the AS info lookup holds it.
func TestGetASWHOISReadsTheStoredDetails(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 storedASN, unstoredASN = 15169, 13335

	_, err = db.GetOrCreateASN(storedASN, time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC))
	if err != nil {
		t.Fatalf("GetOrCreateASN: %v", err)
	}

	update := &ASNWHOISUpdate{
		ASN: storedASN, ASName: "TEST-AS", OrgName: "Test Org", OrgID: "ORG-1",
		Address: "1 Test Street", CountryCode: "DE", AbuseEmail: "abuse@test",
		RIR: "RIPE",
	}

	err = db.UpdateASNWHOIS(t.Context(), update)
	if err != nil {
		t.Fatalf("UpdateASNWHOIS: %v", err)
	}

	got, err := db.GetASWHOIS(t.Context(), storedASN)
	if err != nil {
		t.Fatalf("GetASWHOIS(%d): %v", storedASN, err)
	}

	want := ASN{
		ASN: storedASN, Handle: asinfo.GetHandle(storedASN),
		Description: asinfo.GetDescription(storedASN), ASName: update.ASName,
		OrgName: update.OrgName, OrgID: update.OrgID, Address: update.Address,
		CountryCode: update.CountryCode, AbuseEmail: update.AbuseEmail,
		RIR: update.RIR,
	}

	if got.WHOISUpdatedAt == nil {
		t.Errorf("GetASWHOIS(%d) has no time the details were fetched", storedASN)
	}

	got.WHOISUpdatedAt = nil
	if *got != want {
		t.Errorf("GetASWHOIS(%d) = %+v, want %+v", storedASN, *got, want)
	}

	got, err = db.GetASWHOIS(t.Context(), unstoredASN)
	if err != nil || *got != (ASN{ASN: unstoredASN}) {
		t.Errorf("GetASWHOIS(%d) = %+v, %v; want only the number",
			unstoredASN, got, err)
	}
}

// TestGetPrefixFirstSeenReadsThePrefixTables stores an IPv4 and an IPv6
// prefix and expects GetPrefixFirstSeen to give each its first-seen time, and
// the zero time for a prefix that is not stored.
func TestGetPrefixFirstSeenReadsThePrefixTables(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() }()

	ts := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
	stored := map[string]time.Time{
		"192.0.2.0/24": ts,
		testV6Prefix:   ts.Add(time.Hour),
	}

	err = db.UpdatePrefixesBatch(stored)
	if err != nil {
		t.Fatalf("UpdatePrefixesBatch: %v", err)
	}

	stored["198.51.100.0/24"] = time.Time{}

	for prefix, want := range stored {
		got, err := db.GetPrefixFirstSeen(t.Context(), netip.MustParsePrefix(prefix))
		if err != nil || !got.Equal(want) {
			t.Errorf("GetPrefixFirstSeen(%s) = %v, %v; want %v",
				prefix, got, err, want)
		}
	}
}

// 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.
func TestUpdatePrefixesBatchKeepsFirstSeen(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 known = "198.51.100.0/24"

	first := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
	later := first.Add(time.Hour)

	err = db.UpdatePrefixesBatch(map[string]time.Time{known: first})
	if err != nil {
		t.Fatalf("UpdatePrefixesBatch: %v", err)
	}

	err = db.UpdatePrefixesBatch(map[string]time.Time{
		known: later, testV6Prefix: later,
	})
	if err != nil {
		t.Fatalf("UpdatePrefixesBatch: %v", err)
	}

	stats, err := db.GetStats()
	if err != nil {
		t.Fatalf("GetStats: %v", err)
	}

	if stats.IPv4Prefixes != 1 || stats.IPv6Prefixes != 1 {
		t.Errorf("prefix counts = (v4 %d, v6 %d), want (1, 1)",
			stats.IPv4Prefixes, stats.IPv6Prefixes)
	}

	for _, tt := range []struct {
		query, prefix string
		firstSeen     time.Time
	}{
		{
			query:  "SELECT first_seen FROM prefixes_v4 WHERE prefix = ?",
			prefix: known, firstSeen: first,
		},
		{
			query:  "SELECT first_seen FROM prefixes_v6 WHERE prefix = ?",
			prefix: testV6Prefix, firstSeen: later,
		},
	} {
		var firstSeen time.Time

		err := db.db.QueryRowContext(t.Context(), tt.query, tt.prefix).
			Scan(&firstSeen)
		if err != nil {
			t.Fatalf("reading %s: %v", tt.prefix, err)
		}

		if !firstSeen.Equal(tt.firstSeen) {
			t.Errorf("%s: first seen %s, want %s", tt.prefix, firstSeen,
				tt.firstSeen)
		}
	}
}

// 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)
	}
}

// backlogAge is how much older one write is than the other in the tests of
// first_seen and last_seen, as when a collector catches up on a backlog.
const backlogAge = 24 * time.Hour

// batchSpan is how much earlier a batch's First is than its Last in the tests
// of first_seen and last_seen.
const batchSpan = time.Hour

// TestWritesKeepEarliestFirstSeenAndLatestLastSeen writes a row of each of
// asns, peerings and bgp_peers through each function that writes one, at a
// newer time and at an older one. Each row takes the older write's First as
// first_seen and the newer write's Last as last_seen. The test writes in both
// orders, each in a database of its own. Newer then older is a collector
// catching up on a backlog; older then newer is a feed that arrives in order.
// Each function writes a row of its own. A batch write's First is batchSpan
// before its Last, so the test catches the two swapped. A single-row write
// takes one time.
func TestWritesKeepEarliestFirstSeenAndLatestLastSeen(t *testing.T) {
	t.Parallel()

	const (
		batchASN, singleASN = 64500, 64501
		peerASN             = 64502
		asnQuery            = "SELECT first_seen, last_seen FROM asns WHERE asn = ?"
		peeringQuery        = "SELECT first_seen, last_seen FROM peerings " +
			"WHERE as_a = ? AND as_b = ?"
		peerQuery = "SELECT first_seen, last_seen FROM bgp_peers " +
			"WHERE peer_ip = ?"
	)

	for name, olderFirst := range map[string]bool{
		"newer then older": false,
		"older then newer": true,
	} {
		t.Run(name, func(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() }()

			checkSeenTimes(t, db, olderFirst, func(seen SeenTimes) error {
				return db.GetOrCreateASNBatch(map[int]SeenTimes{batchASN: seen})
			}, batchSpan, asnQuery, batchASN)

			checkSeenTimes(t, db, olderFirst, func(seen SeenTimes) error {
				_, err := db.GetOrCreateASN(singleASN, seen.Last)

				return err
			}, 0, asnQuery, singleASN)

			checkSeenTimes(t, db, olderFirst, func(seen SeenTimes) error {
				return db.RecordPeering(batchASN, singleASN, seen)
			}, batchSpan, peeringQuery, batchASN, singleASN)

			checkSeenTimes(t, db, olderFirst, func(seen SeenTimes) error {
				return db.UpdatePeerBatch(map[string]PeerUpdate{
					testV4PeerIP: {
						PeerIP: testV4PeerIP, PeerASN: peerASN,
						MessageType: ristypes.MessageTypeUpdate,
						Seen:        seen,
					},
				})
			}, batchSpan, peerQuery, testV4PeerIP)

			checkSeenTimes(t, db, olderFirst, func(seen SeenTimes) error {
				return db.UpdatePeer(testPeerIP, peerASN,
					ristypes.MessageTypeUpdate, seen.Last)
			}, 0, peerQuery, testPeerIP)
		})
	}
}

// checkSeenTimes calls write twice, each time with First span before Last: at
// newer times and at times backlogAge older. It writes the older times first
// when olderFirst is true. It checks that query, given args, reads the older
// write's First as first_seen and the newer write's Last as last_seen.
func checkSeenTimes(
	t *testing.T, db *Database, olderFirst bool,
	write func(seen SeenTimes) error,
	span time.Duration, query string, args ...any,
) {
	t.Helper()

	newerLast := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
	newer := SeenTimes{First: newerLast.Add(-span), Last: newerLast}
	older := SeenTimes{
		First: newer.First.Add(-backlogAge),
		Last:  newer.Last.Add(-backlogAge),
	}

	writes := []SeenTimes{newer, older}
	if olderFirst {
		writes = []SeenTimes{older, newer}
	}

	for _, seen := range writes {
		err := write(seen)
		if err != nil {
			t.Fatalf("writing first %s, last %s: %v", seen.First, seen.Last, err)
		}
	}

	var firstSeen, lastSeen time.Time

	err := db.db.QueryRowContext(t.Context(), query, args...).
		Scan(&firstSeen, &lastSeen)
	if err != nil {
		t.Fatalf("reading the row: %v", err)
	}

	if !firstSeen.Equal(older.First) || !lastSeen.Equal(newer.Last) {
		t.Errorf("first seen %s, last seen %s; want %s, %s",
			firstSeen, lastSeen, older.First, newer.Last)
	}
}

// TestGetOrCreateASNReturnsStoredSeenTimes stores an AS at a newer time, then
// at an older one. The second call returns the times the row now holds: the
// older first_seen and the newer last_seen.
func TestGetOrCreateASNReturnsStoredSeenTimes(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 = 64500

	newer := time.Date(2026, 1, 2, 3, 4, 5, 0, time.UTC)
	older := newer.Add(-backlogAge)

	_, err = db.GetOrCreateASN(asn, newer)
	if err != nil {
		t.Fatalf("GetOrCreateASN at %s: %v", newer, err)
	}

	got, err := db.GetOrCreateASN(asn, older)
	if err != nil {
		t.Fatalf("GetOrCreateASN at %s: %v", older, err)
	}

	if !got.FirstSeen.Equal(older) || !got.LastSeen.Equal(newer) {
		t.Errorf("first seen %s, last seen %s; want %s, %s",
			got.FirstSeen, got.LastSeen, older, newer)
	}
}