diff --git a/TODO.md b/TODO.md index c4059a0..2336169 100644 --- a/TODO.md +++ b/TODO.md @@ -22,6 +22,15 @@ the tag exists and is exercised; what is left is merging `next` to # Completed Steps +- 2026-10-06: Made the local index actually run in WAL mode with a busy + timeout ([issue #217](https://git.eeqj.de/sneak/vaultik/issues/217)). + The connection settings were written in a form the SQLite driver + ignores, so the index ran without either and `snapshot list` or `info` + during a backup could make the backup's next write fail with + `database is locked`. They are now `_pragma=` parameters, and the + metadata export copies the open index with `VACUUM INTO`, because a + copy of the file alone misses rows still in the `-wal` file. + - 2026-10-06: Made a backup record the real uid and gid of files, directories and symlinks ([issue #216](https://git.eeqj.de/sneak/vaultik/issues/216)). The diff --git a/docs/DATAMODEL.md b/docs/DATAMODEL.md index 37e128e..4fe62a5 100644 --- a/docs/DATAMODEL.md +++ b/docs/DATAMODEL.md @@ -280,7 +280,7 @@ This ensures consistency, especially important for operations like: 3. **Batch Operations**: Where possible, operations are batched within transactions -4. **Write-Ahead Logging**: SQLite WAL mode is enabled for better concurrency +4. **Write-Ahead Logging**: The local index runs in SQLite WAL mode with a 10-second busy timeout, so a read-only command such as `snapshot list` can read it while a backup writes to it. Committed rows can sit in the `-wal` file beside the index until a checkpoint, so the metadata export copies the index through SQLite (`VACUUM INTO`), not as a file ## Data Integrity diff --git a/internal/database/database.go b/internal/database/database.go index b41945b..7950ade 100644 --- a/internal/database/database.go +++ b/internal/database/database.go @@ -42,6 +42,10 @@ var schemaFS embed.FS // table itself. It is applied before the normal migration loop. const bootstrapVersion = 0 +// busyTimeoutMsec is how long a connection to the index waits for another +// connection's lock before failing with "database is locked". +const busyTimeoutMsec = 10000 + // DB represents the Vaultik local index database connection. // It uses SQLite to track file metadata, content-defined chunks, and blob associations. // The database enables incremental backups by detecting changed files and @@ -94,10 +98,27 @@ func ParseMigrationVersion(filename string) (int, error) { return version, nil } +// indexDSN returns the driver DSN that opens the database at path. The +// driver runs each _pragma parameter on every connection it opens and drops +// any parameter it does not know without an error, so a setting written in +// another form silently does nothing. In WAL mode one connection can write +// while others read; the busy timeout makes a connection wait for a lock +// instead of failing at once. +func indexDSN(path string) string { + return fmt.Sprintf( + "%s?_pragma=busy_timeout(%d)&_pragma=journal_mode(WAL)"+ + "&_pragma=synchronous(NORMAL)&_pragma=foreign_keys(1)", + path, busyTimeoutMsec) +} + // New creates a new database connection at the specified path. -// It creates the schema if needed and configures SQLite with WAL mode for -// better concurrency. SQLite handles crash recovery automatically when -// opening a database with journal/WAL files present. +// It creates the schema if needed. Every connection runs in WAL mode with +// a busy timeout and foreign keys on (see indexDSN), so a read-only command +// can read the index while a backup writes to it. Committed rows can sit in +// the -wal file beside the database until a checkpoint, so a copy of the +// database file alone may miss them. +// SQLite handles crash recovery automatically when opening a database with +// journal/WAL files present. // The path parameter can be a file path for persistent storage or ":memory:" // for an in-memory database (useful for testing). func New(ctx context.Context, path string) (*DB, error) { @@ -110,11 +131,7 @@ func New(ctx context.Context, path string) (*DB, error) { // First attempt with standard WAL mode log.Debug("Attempting to open database with WAL mode", "path", path) - conn, err := sql.Open( - "sqlite", - path+"?_journal_mode=WAL&_synchronous=NORMAL&_busy_timeout=10000"+ - "&_locking_mode=NORMAL&_foreign_keys=ON", - ) + conn, err := sql.Open("sqlite", indexDSN(path)) if err == nil { configureConnPool(conn) @@ -134,7 +151,7 @@ func New(ctx context.Context, path string) (*DB, error) { _ = conn.Close() } - // If first attempt failed, try with TRUNCATE mode to clear any locks + // If the first attempt failed, try once more return openWithRecovery(ctx, path) } @@ -147,18 +164,12 @@ func configureConnPool(conn *sql.DB) { conn.SetMaxIdleConns(1) } -// finishOpen enables foreign keys, wraps the connection, and applies any -// pending migrations. On migration failure the connection is closed. +// finishOpen wraps the connection and applies any pending migrations. On +// migration failure the connection is closed. func finishOpen(ctx context.Context, conn *sql.DB, path string) (*DB, error) { - // Enable foreign keys explicitly - _, err := conn.ExecContext(ctx, "PRAGMA foreign_keys = ON") - if err != nil { - log.Warn("Failed to enable foreign keys", "path", path, "error", err) - } - db := &DB{conn: conn, path: path} - err = applyMigrations(ctx, conn) + err := applyMigrations(ctx, conn) if err != nil { _ = conn.Close() @@ -168,21 +179,15 @@ func finishOpen(ctx context.Context, conn *sql.DB, path string) (*DB, error) { return db, nil } -// openWithRecovery retries opening the database in TRUNCATE journal mode to -// clear stale locks, then switches back to WAL mode. +// openWithRecovery makes a second attempt to open the database, with the +// same settings, after the first attempt failed, for example because +// another process held a lock for longer than the busy timeout. func openWithRecovery(ctx context.Context, path string) (*DB, error) { - log.Info( - "Database appears locked, attempting recovery with TRUNCATE mode", - "path", path, - ) + log.Info("Database appears locked, retrying open", "path", path) - conn, err := sql.Open( - "sqlite", - path+"?_journal_mode=TRUNCATE&_synchronous=NORMAL&_busy_timeout=10000"+ - "&_foreign_keys=ON", - ) + conn, err := sql.Open("sqlite", indexDSN(path)) if err != nil { - return nil, fmt.Errorf("opening database in recovery mode: %w", err) + return nil, fmt.Errorf("opening database on retry: %w", err) } configureConnPool(conn) @@ -190,7 +195,7 @@ func openWithRecovery(ctx context.Context, path string) (*DB, error) { err = conn.PingContext(ctx) if err != nil { log.Debug( - "Failed to ping database in recovery mode, closing", + "Failed to ping database on retry, closing", "path", path, "error", err, ) @@ -202,16 +207,6 @@ func openWithRecovery(ctx context.Context, path string) (*DB, error) { ) } - log.Debug("Database opened in TRUNCATE mode", "path", path) - - // Switch back to WAL mode - log.Debug("Switching database back to WAL mode", "path", path) - - _, err = conn.ExecContext(ctx, "PRAGMA journal_mode=WAL") - if err != nil { - log.Warn("Failed to switch back to WAL mode", "path", path, "error", err) - } - db, err := finishOpen(ctx, conn, path) if err != nil { return nil, err diff --git a/internal/database/database_test.go b/internal/database/database_test.go index 24cf416..700535d 100644 --- a/internal/database/database_test.go +++ b/internal/database/database_test.go @@ -120,6 +120,89 @@ func TestDatabaseConcurrentAccess(t *testing.T) { } } +// TestNewSetsJournalModeAndBusyTimeout checks that the connection settings +// New passes reach SQLite. The driver drops a setting it does not recognise +// without an error, so only reading the value back shows it took effect. +func TestNewSetsJournalModeAndBusyTimeout(t *testing.T) { + t.Parallel() + + ctx := context.Background() + + db, err := New(ctx, filepath.Join(t.TempDir(), "index.db")) + if err != nil { + t.Fatalf("failed to create database: %v", err) + } + + defer func() { _ = db.Close() }() + + var journalMode string + + err = db.conn.QueryRowContext(ctx, "PRAGMA journal_mode").Scan(&journalMode) + if err != nil { + t.Fatalf("reading journal_mode: %v", err) + } + + if journalMode != "wal" { + t.Errorf("journal_mode = %q, want %q", journalMode, "wal") + } + + var busyTimeout int + + err = db.conn.QueryRowContext(ctx, "PRAGMA busy_timeout").Scan(&busyTimeout) + if err != nil { + t.Fatalf("reading busy_timeout: %v", err) + } + + if busyTimeout != busyTimeoutMsec { + t.Errorf("busy_timeout = %d, want %d", busyTimeout, busyTimeoutMsec) + } +} + +// TestNewWriteSucceedsWhileAnotherHandleReads opens the same index twice, +// as a read-only command does while a backup runs, and checks that a write +// on one handle commits while the other is in the middle of a read. +func TestNewWriteSucceedsWhileAnotherHandleReads(t *testing.T) { + t.Parallel() + + ctx := context.Background() + dbPath := filepath.Join(t.TempDir(), "index.db") + + reader, err := New(ctx, dbPath) + if err != nil { + t.Fatalf("failed to open reading handle: %v", err) + } + + defer func() { _ = reader.Close() }() + + writer, err := New(ctx, dbPath) + if err != nil { + t.Fatalf("failed to open writing handle: %v", err) + } + + defer func() { _ = writer.Close() }() + + // The read lock taken by the SELECT is held until the transaction ends. + readTx, err := reader.BeginTx(ctx, nil) + if err != nil { + t.Fatalf("beginning read transaction: %v", err) + } + + defer func() { _ = readTx.Rollback() }() + + var count int + + err = readTx.QueryRowContext(ctx, "SELECT COUNT(*) FROM chunks").Scan(&count) + if err != nil { + t.Fatalf("reading chunks: %v", err) + } + + _, err = writer.ExecWithLog(ctx, + "INSERT INTO chunks (chunk_hash, size) VALUES (?, ?)", "hash", 1024) + if err != nil { + t.Fatalf("write while another handle reads: %v", err) + } +} + func TestParseMigrationVersion(t *testing.T) { t.Parallel() diff --git a/internal/snapshot/export_perm_test.go b/internal/snapshot/export_perm_test.go index 84e407a..12d79e9 100644 --- a/internal/snapshot/export_perm_test.go +++ b/internal/snapshot/export_perm_test.go @@ -1,40 +1,48 @@ -//nolint:testpackage // exercises the unexported copyFile helper +//nolint:testpackage // exercises the unexported copyDatabase helper package snapshot import ( + "context" "os" "path/filepath" "syscall" "testing" "github.com/spf13/afero" + "sneak.berlin/go/vaultik/internal/database" ) -// TestCopyFileExportCopyMode verifies that the exported snapshot database -// copy is created owner-only (0600), even under a lenient 022 umask that -// would otherwise leave a fresh file world-readable. +// TestCopyDatabaseExportCopyMode verifies that the exported snapshot +// database copy is created owner-only (0600), even under a lenient 022 +// umask that would otherwise leave a fresh file world-readable. // //nolint:paralleltest // syscall.Umask is process-global; parallel tests would clash -func TestCopyFileExportCopyMode(t *testing.T) { +func TestCopyDatabaseExportCopyMode(t *testing.T) { restore := syscall.Umask(0o022) defer syscall.Umask(restore) + ctx := context.Background() dir := t.TempDir() src := filepath.Join(dir, "index.sqlite") - err := os.WriteFile(src, []byte("index data"), 0o600) + db, err := database.New(ctx, src) if err != nil { t.Fatalf("creating source index: %v", err) } + err = db.Close() + if err != nil { + t.Fatalf("closing source index: %v", err) + } + dst := filepath.Join(dir, "snapshot.db") sm := &SnapshotManager{fs: afero.NewOsFs()} - err = sm.copyFile(src, dst) + err = sm.copyDatabase(ctx, src, dst) if err != nil { - t.Fatalf("copyFile: %v", err) + t.Fatalf("copyDatabase: %v", err) } info, err := os.Stat(dst) diff --git a/internal/snapshot/snapshot.go b/internal/snapshot/snapshot.go index 2fac581..82a12a7 100644 --- a/internal/snapshot/snapshot.go +++ b/internal/snapshot/snapshot.go @@ -386,12 +386,12 @@ func (sm *SnapshotManager) prepareExportDB( ctx context.Context, dbPath, snapshotID, tempDir string, ) ([]byte, string, error) { // Step 1: Copy database to temp file - // The main database should be closed at this point + // The main database is still open here, so it is copied through SQLite tempDBPath := filepath.Join(tempDir, "snapshot.db") log.Debug("Copying database to temporary location", "source", dbPath, "destination", tempDBPath) - err := sm.copyFile(dbPath, tempDBPath) + err := sm.copyDatabase(ctx, dbPath, tempDBPath) if err != nil { return nil, "", fmt.Errorf("copying database: %w", err) } @@ -648,9 +648,10 @@ func (sm *SnapshotManager) collectCleanupStats( // // VACUUM runs through the modernc.org/sqlite driver, on a freshly opened // connection with no transaction in flight (VACUUM cannot run inside one). -// The database opens in WAL mode, so VACUUM's rewrite lands in the WAL; the -// checkpoint on Close flushes it into the main file, which is the file we -// then compress and upload. +// database.New opens the file in WAL mode, so VACUUM's rewrite lands in the +// -wal file. This is the only connection to the file, so closing it +// checkpoints the rewrite into the main file and removes the -wal file; the +// main file is the one compressFile then compresses and uploads. func (sm *SnapshotManager) vacuumDatabase(ctx context.Context, dbPath string) error { log.Debug("Running VACUUM on database", "path", dbPath) @@ -744,26 +745,15 @@ func (sm *SnapshotManager) compressFile(inputPath, outputPath string) error { // user; it holds the same private index data as the local index file. const exportCopyPerm = 0o600 -// copyFile copies a file from src to dst. The destination is the exported -// snapshot database, so it is created owner-only rather than with the -// umask-dependent default. -func (sm *SnapshotManager) copyFile(src, dst string) error { - log.Debug("Opening source file for copy", "path", src) - - sourceFile, err := sm.fs.Open(src) - if err != nil { - return err - } - - defer func() { - log.Debug("Closing source file", "path", src) - - err := sourceFile.Close() - if err != nil { - log.Debug("Failed to close source file", "path", src, "error", err) - } - }() - +// copyDatabase copies the database at src to dst with VACUUM INTO. It reads +// through SQLite, so the copy holds rows committed to src that are still in +// its -wal file, which a copy of the file alone would miss. The destination +// is the exported snapshot database, so it is created empty and owner-only +// first rather than with the umask-dependent default: VACUUM INTO writes +// into an existing empty file and keeps its mode. +func (sm *SnapshotManager) copyDatabase( + ctx context.Context, src, dst string, +) error { log.Debug("Creating destination file", "path", dst) destFile, err := sm.fs.OpenFile( @@ -773,23 +763,28 @@ func (sm *SnapshotManager) copyFile(src, dst string) error { return err } - defer func() { - log.Debug("Closing destination file", "path", dst) - - err := destFile.Close() - if err != nil { - log.Debug("Failed to close destination file", "path", dst, "error", err) - } - }() - - log.Debug("Copying file data") - - n, err := io.Copy(destFile, sourceFile) + err = destFile.Close() if err != nil { return err } - log.Debug("File copy complete", "bytes_copied", n) + db, err := database.New(ctx, src) + if err != nil { + return fmt.Errorf("opening database to copy: %w", err) + } + + defer func() { + cerr := db.Close() + if cerr != nil { + log.Debug("Failed to close database after copy", + "path", src, "error", cerr) + } + }() + + _, err = db.ExecWithLog(ctx, "VACUUM INTO ?", dst) + if err != nil { + return fmt.Errorf("running VACUUM INTO: %w", err) + } return nil } diff --git a/internal/snapshot/snapshot_test.go b/internal/snapshot/snapshot_test.go index 42061a2..a0b31bc 100644 --- a/internal/snapshot/snapshot_test.go +++ b/internal/snapshot/snapshot_test.go @@ -188,6 +188,77 @@ func TestVacuumDatabaseRemovesDeletedData(t *testing.T) { } } +// TestPrepareExportDBKeepsRowsCommittedToOpenIndex exports from an index +// that is still open, as a backup does. A row committed there can still be +// in the index's -wal file, and the export must hold it all the same. +func TestPrepareExportDBKeepsRowsCommittedToOpenIndex(t *testing.T) { + log.Initialize(log.Config{}) + t.Parallel() + + ctx := context.Background() + fs := afero.NewOsFs() + + dbPath := filepath.Join(t.TempDir(), "index.sqlite") + + db, err := database.New(ctx, dbPath) + if err != nil { + t.Fatalf("failed to create database: %v", err) + } + + defer func() { _ = db.Close() }() + + repos := database.NewRepositories(db) + + snapshot := &database.Snapshot{ID: "open-index-snapshot", Hostname: "test-host"} + + err = repos.WithTx(ctx, func(ctx context.Context, tx *sql.Tx) error { + return repos.Snapshots.Create(ctx, tx, snapshot) + }) + if err != nil { + t.Fatalf("failed to create snapshot: %v", err) + } + + sm := &SnapshotManager{ + config: &config.Config{ + CompressionLevel: 3, + AgeRecipients: []string{testAgeRecipient}, + }, + fs: fs, + } + + _, tempDBPath, err := sm.prepareExportDB( + ctx, dbPath, snapshot.ID.String(), t.TempDir()) + if err != nil { + t.Fatalf("prepareExportDB failed: %v", err) + } + + // Only the main database file is compressed and uploaded, so open a + // copy of that file alone. + uploadedPath := filepath.Join(t.TempDir(), "uploaded.db") + + err = copyFile(fs, tempDBPath, uploadedPath) + if err != nil { + t.Fatalf("failed to copy exported database: %v", err) + } + + exported, err := database.OpenReadOnly(ctx, uploadedPath) + if err != nil { + t.Fatalf("failed to open exported database: %v", err) + } + + defer func() { _ = exported.Close() }() + + got, err := database.NewRepositories(exported).Snapshots.GetByID( + ctx, snapshot.ID.String()) + if err != nil { + t.Fatalf("failed to read snapshot from export: %v", err) + } + + if got == nil { + t.Fatal("exported database is missing the snapshot row") + } +} + func TestCleanSnapshotDBEmptySnapshot(t *testing.T) { // Initialize logger log.Initialize(log.Config{})