Report or refuse each unusable file webhooker reads (closes #290)

Audit of the files webhooker reads configuration or required state
from. A missing or zero-length database is reported with the "created
a new, empty database" warning and its path: webhooker.db at start,
and a per-webhook database at the latest at the next start, since
restart recovery now opens the database of every webhook that still
exists. The main database's open errors name webhooker.db
(#459). webhooker resetpw
refuses a zero-length webhooker.db as it refuses a missing one. A
directory in place of a database file or its -wal or -shm is refused,
naming it; beside a -shm directory SQLite opened the database
read-only without a word. The README says how each case is treated.

Model: opus-5-5

internal/database/bootstrap_banner_test.go

@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"context"
 	"log/slog"
+	"os"
 	"path/filepath"
 	"strings"
 	"testing"
@@ -119,3 +120,26 @@ func TestNewDatabase_IsLoggedWithItsPath(t *testing.T) {
 		t, second, created, "an existing database is not new",
 	)
 }
+
+// TestZeroLengthDatabase_IsLoggedAsNew covers what
+// https://git.eeqj.de/sneak/webhooker/issues/290 found: SQLite opens a
+// zero-length file as an empty database, so a start on one is a first
+// start, and it must say so exactly as a start with no file does.
+func TestZeroLengthDatabase_IsLoggedAsNew(t *testing.T) {
+	t.Parallel()
+
+	dir := t.TempDir()
+	path := filepath.Join(dir, database.MainDBFileName)
+	require.NoError(t, os.WriteFile(path, nil, database.SQLiteFilePerm))
+
+	var out bytes.Buffer
+
+	db, err := database.Open(dir, slog.New(slog.NewTextHandler(&out, nil)))
+	require.NoError(t, err)
+	require.NoError(t, db.Close())
+
+	assert.Contains(
+		t, out.String(),
+		`level=WARN msg="created a new, empty database" path=`+path,
+	)
+}

internal/database/database.go

@@ -8,7 +8,6 @@ import (
 	"errors"
 	"fmt"
 	"io"
-	"io/fs"
 	"log/slog"
 	"os"
 	"path/filepath"
@@ -203,8 +202,7 @@ func (d *Database) connectTo(dataDir string) error {
 	// Checked before opening, which creates the file. A DATA_DIR that
 	// is unexpectedly empty -- its volume not mounted, say -- looks
 	// exactly like a first start, so a new database is a warning.
-	_, statErr := os.Stat(dbPath)
-	created := errors.Is(statErr, fs.ErrNotExist)
+	created := missingOrEmpty(dbPath)
 
 	// Opened through OpenSQLite so this handle carries the same WAL
 	// journaling, busy timeout, immediate-transaction locking, and pool
@@ -213,13 +211,15 @@ func (d *Database) connectTo(dataDir string) error {
 	if err != nil {
 		d.log.Error(
 			"failed to open database",
+			"path", dbPath,
 			"error", err,
 		)
 
 		return err
 	}
 
-	// Then use it with GORM
+	// Then use it with GORM. Its errors are SQLite's alone and name no
+	// file, so the path is added to them here.
 	db, err := gorm.Open(sqlite.Dialector{
 		Conn: sqlDB,
 	}, &gorm.Config{
@@ -229,10 +229,11 @@ func (d *Database) connectTo(dataDir string) error {
 	if err != nil {
 		d.log.Error(
 			"failed to connect to database",
+			"path", dbPath,
 			"error", err,
 		)
 
-		return err
+		return fmt.Errorf("connecting to %s: %w", dbPath, err)
 	}
 
 	d.db = db
@@ -243,8 +244,12 @@ func (d *Database) connectTo(dataDir string) error {
 		d.log.Info("connected to database", "path", dbPath)
 	}
 
-	// Run migrations
-	return d.migrate()
+	err = d.migrate()
+	if err != nil {
+		return fmt.Errorf("migrating %s: %w", dbPath, err)
+	}
+
+	return nil
 }
 
 func (d *Database) migrate() error {

internal/database/database_test.go

@@ -1,9 +1,15 @@
 package database_test
 
 import (
+	"bytes"
 	"context"
+	"log/slog"
+	"os"
+	"path/filepath"
 	"testing"
 
+	"github.com/stretchr/testify/assert"
+	"github.com/stretchr/testify/require"
 	"go.uber.org/fx/fxtest"
 	"sneak.berlin/go/webhooker/internal/config"
 	"sneak.berlin/go/webhooker/internal/database"
@@ -100,3 +106,22 @@ func TestDatabaseConnection(t *testing.T) {
 		)
 	}
 }
+
+// TestOpen_UnreadableDatabaseIsNamed pins
+// https://git.eeqj.de/sneak/webhooker/issues/459: when SQLite cannot
+// read webhooker.db, the error that stops the server and `webhooker
+// resetpw` names the file, not only SQLite's own message.
+func TestOpen_UnreadableDatabaseIsNamed(t *testing.T) {
+	t.Parallel()
+
+	dir := t.TempDir()
+	path := filepath.Join(dir, database.MainDBFileName)
+	require.NoError(t, os.WriteFile(
+		path, bytes.Repeat([]byte("junk"), 1024), database.SQLiteFilePerm,
+	))
+
+	_, err := database.Open(dir, slog.New(slog.DiscardHandler))
+	require.Error(t, err)
+	assert.Contains(t, err.Error(), path)
+	assert.Contains(t, err.Error(), "file is not a database")
+}

internal/database/retention.go

@@ -184,8 +184,8 @@ func (r *RetentionReaper) sweep(ctx context.Context) {
 
 		wh := webhooks[i]
 
-		// Nothing to reap if the per-webhook database has never
-		// been created.
+		// A missing database has nothing to reap. Restart recovery
+		// reports a lost one (see WebhookDBManager.GetDB).
 		if !r.dbManager.DBExists(wh.ID) {
 			continue
 		}

internal/database/sqlite_mode_test.go

@@ -182,6 +182,29 @@ func TestOpenSQLiteTightensFilesLeftWorldReadable(t *testing.T) {
 	requireDatabaseSetOwnerOnly(t, path)
 }
 
+// TestOpenSQLiteRefusesADirectorySidecar covers a directory in place
+// of -wal or -shm. Beside a -shm directory SQLite opens the database
+// read-only without a word, and every write then fails naming no file,
+// so the open must stop instead, naming the directory.
+func TestOpenSQLiteRefusesADirectorySidecar(t *testing.T) {
+	t.Parallel()
+
+	for _, suffix := range []string{"-wal", "-shm"} {
+		t.Run(suffix, func(t *testing.T) {
+			t.Parallel()
+
+			path := filepath.Join(t.TempDir(), database.MainDBFileName)
+			require.NoError(t, os.Mkdir(path+suffix, 0o700))
+
+			_, err := database.OpenSQLite(
+				path, database.SQLiteModeCreate,
+			)
+			require.Error(t, err)
+			assert.Contains(t, err.Error(), path+suffix)
+		})
+	}
+}
+
 // TestOpenSQLiteExistingModeDoesNotCreateTheFile guards the mechanism
 // the fix uses: OpenSQLite now creates the database file itself, and
 // must not do so for a caller that asked for an existing database. An

internal/database/sqlite_open.go

@@ -7,6 +7,7 @@ import (
 	"io/fs"
 	"net/url"
 	"os"
+	"syscall"
 	"time"
 
 	_ "modernc.org/sqlite" // Pure Go SQLite driver
@@ -93,7 +94,8 @@ const (
 const SQLiteFilePerm fs.FileMode = 0o600
 
 // reserveSQLiteFile puts path at SQLiteFilePerm before the driver ever
-// touches it, and tightens any sidecar already on disk.
+// touches it, and tightens any sidecar already on disk. A directory in
+// place of any of them is an error naming it.
 //
 // The mode has to be settled here rather than by a chmod after opening,
 // because SQLite picks it: robust_open substitutes
@@ -143,7 +145,15 @@ func reserveSQLiteFile(path string, create bool) error {
 	for _, p := range append(
 		[]string{path}, sqliteSidecarPaths(path)...,
 	) {
-		err := os.Chmod(p, SQLiteFilePerm)
+		// Chmod accepts a directory, and SQLite opens a database whose
+		// -shm is one read-only, without a word: every write then
+		// fails naming no file.
+		info, err := os.Stat(p)
+		if err == nil && info.IsDir() {
+			return fmt.Errorf("securing %s: %w", p, syscall.EISDIR)
+		}
+
+		err = os.Chmod(p, SQLiteFilePerm)
 		if err != nil && !errors.Is(err, fs.ErrNotExist) {
 			return fmt.Errorf("securing %s: %w", p, err)
 		}
@@ -152,6 +162,20 @@ func reserveSQLiteFile(path string, create bool) error {
 	return nil
 }
 
+// missingOrEmpty reports whether opening path in SQLiteModeCreate
+// would start a new, empty database: the file is not there, or it is
+// zero-length, which SQLite opens as an empty database. A file left at
+// zero length by an interrupted first start or a truncated copy holds
+// as little as a missing one, and must be reported the same way.
+func missingOrEmpty(path string) bool {
+	info, err := os.Stat(path)
+	if errors.Is(err, fs.ErrNotExist) {
+		return true
+	}
+
+	return err == nil && info.Size() == 0
+}
+
 // sqliteSidecarPaths returns the files SQLite maintains beside a
 // database under WAL. They carry the same rows as the database itself,
 // so a fix that tightens only the main file has fixed nothing.

internal/database/webhook_db_manager.go

@@ -98,34 +98,18 @@ func NewWebhookDBManager(
 	return m, nil
 }
 
-// GetDB returns the database connection for a webhook,
-// creating the database file lazily if it doesn't exist.
+// GetDB returns the database connection for a webhook, opening it on
+// first use.
+//
+// The file is made by CreateDB when the webhook is created. One that is
+// missing or zero-length here means the webhook's events and pending
+// deliveries are gone: an empty database is created in its place so
+// the webhook keeps receiving, and that is logged as a warning naming
+// the file, as a new main database is.
 func (m *WebhookDBManager) GetDB(
 	webhookID string,
 ) (*gorm.DB, error) {
-	// Fast path: already open
-	if val, ok := m.dbs.Load(webhookID); ok {
-		return asGormDB(val, webhookID)
-	}
-
-	// Slow path: open the database under the lock, looking in the
-	// cache again first. A caller that raced another one here then
-	// waits for its handle instead of opening a second one.
-	m.mu.Lock()
-	defer m.mu.Unlock()
-
-	if val, ok := m.dbs.Load(webhookID); ok {
-		return asGormDB(val, webhookID)
-	}
-
-	db, err := m.openDB(webhookID)
-	if err != nil {
-		return nil, err
-	}
-
-	m.dbs.Store(webhookID, db)
-
-	return db, nil
+	return m.getDB(webhookID, false)
 }
 
 // asGormDB returns a value read from the cache as the database
@@ -143,12 +127,12 @@ func asGormDB(val any, webhookID string) (*gorm.DB, error) {
 	return db, nil
 }
 
-// CreateDB explicitly creates a new per-webhook database file
-// and runs migrations.
+// CreateDB creates a new webhook's database file and runs
+// migrations.
 func (m *WebhookDBManager) CreateDB(
 	webhookID string,
 ) error {
-	_, err := m.GetDB(webhookID)
+	_, err := m.getDB(webhookID, true)
 
 	return err
 }
@@ -266,6 +250,48 @@ func (m *WebhookDBManager) DBPath(
 	return m.dbPath(webhookID)
 }
 
+// getDB is GetDB, and CreateDB when isNew is true: the webhook has just
+// been created, so a missing file is expected rather than lost.
+func (m *WebhookDBManager) getDB(
+	webhookID string, isNew bool,
+) (*gorm.DB, error) {
+	// Fast path: already open
+	if val, ok := m.dbs.Load(webhookID); ok {
+		return asGormDB(val, webhookID)
+	}
+
+	// Slow path: open the database under the lock, looking in the
+	// cache again first. A caller that raced another one here then
+	// waits for its handle instead of opening a second one.
+	m.mu.Lock()
+	defer m.mu.Unlock()
+
+	if val, ok := m.dbs.Load(webhookID); ok {
+		return asGormDB(val, webhookID)
+	}
+
+	// Checked before opening, which creates the file. See GetDB.
+	path := m.dbPath(webhookID)
+	replaced := !isNew && missingOrEmpty(path)
+
+	db, err := m.openDB(webhookID)
+	if err != nil {
+		return nil, err
+	}
+
+	if replaced {
+		m.log.Warn(
+			"created a new, empty database",
+			"webhook_id", webhookID,
+			"path", path,
+		)
+	}
+
+	m.dbs.Store(webhookID, db)
+
+	return db, nil
+}
+
 func (m *WebhookDBManager) dbPath(
 	webhookID string,
 ) string {

internal/database/webhook_db_manager_test.go

@@ -289,6 +289,75 @@ func TestWebhookDBManager_LazyCreation(t *testing.T) {
 	assert.True(t, mgr.DBExists(webhookID))
 }
 
+// A webhook's database is made by CreateDB along with the webhook. One
+// that GetDB finds missing or zero-length has lost the webhook's events
+// and pending deliveries, so the empty database made in its place is
+// logged as a warning naming the file
+// (https://git.eeqj.de/sneak/webhooker/issues/290). CreateDB, and
+// reopening a database that is there, log no such warning.
+func TestWebhookDBManager_LostDatabaseIsLogged(t *testing.T) {
+	t.Parallel()
+
+	const created = `level=WARN msg="created a new, empty database"`
+
+	open := func(
+		t *testing.T, prepare func(*database.WebhookDBManager, string),
+	) (string, string) {
+		t.Helper()
+
+		var logs bytes.Buffer
+
+		mgr := database.NewTestWebhookDBManagerWithLogger(
+			t.TempDir(),
+			slog.New(slog.NewTextHandler(&logs, nil)),
+		)
+
+		webhookID := uuid.New().String()
+		prepare(mgr, webhookID)
+
+		_, err := mgr.GetDB(webhookID)
+		require.NoError(t, err)
+		require.NoError(t, mgr.CloseAll())
+
+		return logs.String(),
+			" webhook_id=" + webhookID + " path=" + mgr.DBPath(webhookID)
+	}
+
+	t.Run("missing", func(t *testing.T) {
+		t.Parallel()
+
+		logs, fields := open(
+			t, func(*database.WebhookDBManager, string) {},
+		)
+		assert.Contains(t, logs, created+fields)
+	})
+
+	t.Run("zero-length", func(t *testing.T) {
+		t.Parallel()
+
+		logs, fields := open(
+			t, func(mgr *database.WebhookDBManager, webhookID string) {
+				require.NoError(t, os.WriteFile(
+					mgr.DBPath(webhookID), nil, database.SQLiteFilePerm,
+				))
+			},
+		)
+		assert.Contains(t, logs, created+fields)
+	})
+
+	t.Run("created with the webhook, then reopened", func(t *testing.T) {
+		t.Parallel()
+
+		logs, _ := open(
+			t, func(mgr *database.WebhookDBManager, webhookID string) {
+				require.NoError(t, mgr.CreateDB(webhookID))
+				require.NoError(t, mgr.CloseAll())
+			},
+		)
+		assert.NotContains(t, logs, created)
+	})
+}
+
 func TestWebhookDBManager_DeliveryWorkflow(t *testing.T) {
 	t.Parallel()