navidrome/db/db.go
Deluan 56a36e4da4 feat(persistence): log SQLite result codes on failed statements
SQLite reuses one message for errors that need different responses: "database
is locked" is both SQLITE_BUSY, which busy_timeout retries, and
SQLITE_BUSY_SNAPSHOT, which it can never retry because the transaction's read
snapshot is already stale. Reading only the message, the two are
indistinguishable, and a lock error seen in the wild could not be diagnosed
without guessing which one it was.

Add db.ErrorCodes to unwrap a sqlite3.Error and report its result and extended
result codes, and include them in the SQL error log. The helper lives in db
because that package already owns the driver, so persistence does not need to
import it. Constraint, readonly and disk-full errors share messages the same
way, so this applies to every failed statement, not just locks.
2026-07-29 08:49:17 -04:00

184 lines
4.5 KiB
Go

package db
import (
"context"
"database/sql"
"embed"
"errors"
"fmt"
"time"
"github.com/mattn/go-sqlite3"
"github.com/navidrome/navidrome/conf"
_ "github.com/navidrome/navidrome/db/migrations"
"github.com/navidrome/navidrome/log"
"github.com/navidrome/navidrome/utils/hasher"
"github.com/navidrome/navidrome/utils/singleton"
"github.com/pressly/goose/v3"
)
var (
Dialect = "sqlite3"
Driver = Dialect + "_custom"
Path string
)
//go:embed migrations/*.sql
var embedMigrations embed.FS
const migrationsFolder = "migrations"
func Db() *sql.DB {
return singleton.GetInstance(func() *sql.DB {
sql.Register(Driver, &sqlite3.SQLiteDriver{
ConnectHook: func(conn *sqlite3.SQLiteConn) error {
return conn.RegisterFunc("SEEDEDRAND", hasher.HashFunc(), false)
},
})
Path = conf.Server.DbPath
if Path == ":memory:" {
Path = "file::memory:?cache=shared&_foreign_keys=on"
conf.Server.DbPath = Path
} else {
conf.Server.DataFolder.MustPath()
}
log.Debug("Opening DataBase", "dbPath", Path, "driver", Driver)
db, err := sql.Open(Driver, Path)
db.SetMaxOpenConns(conf.MaxOpenConns())
if err != nil {
log.Fatal("Error opening database", err)
}
return db
})
}
func Close(ctx context.Context) {
// Ignore cancellations when closing the DB
ctx = context.WithoutCancel(ctx)
log.Info(ctx, "Closing Database")
err := Db().Close()
if err != nil {
log.Error(ctx, "Error closing Database", err)
}
}
func Init(ctx context.Context) func() {
db := Db()
// Disable foreign_keys to allow re-creating tables in migrations
_, err := db.ExecContext(ctx, "PRAGMA foreign_keys=off")
defer func() {
_, err := db.ExecContext(ctx, "PRAGMA foreign_keys=on")
if err != nil {
log.Error(ctx, "Error re-enabling foreign_keys", err)
}
}()
if err != nil {
log.Error(ctx, "Error disabling foreign_keys", err)
}
goose.SetBaseFS(embedMigrations)
err = goose.SetDialect(Dialect)
if err != nil {
log.Fatal(ctx, "Invalid DB driver", "driver", Driver, err)
}
schemaEmpty := isSchemaEmpty(ctx, db)
hasSchemaChanges := hasPendingMigrations(ctx, db, migrationsFolder)
if !schemaEmpty && hasSchemaChanges {
log.Info(ctx, "Upgrading DB Schema to latest version")
}
goose.SetLogger(&logAdapter{ctx: ctx, silent: schemaEmpty})
err = goose.UpContext(ctx, db, migrationsFolder)
if err != nil {
log.Fatal(ctx, "Failed to apply new migrations", err)
}
if hasSchemaChanges {
log.Debug(ctx, "Running ANALYZE after schema changes")
err = optimizeAt(ctx, db, time.Now())
if err != nil {
log.Error(ctx, "Error running ANALYZE", err)
}
}
return func() {
Close(ctx)
}
}
// ErrorCodes reports the SQLite result code and extended result code carried by err.
// The extended code is what distinguishes errors that share a message: "database is locked"
// is both SQLITE_BUSY, which busy_timeout retries, and SQLITE_BUSY_SNAPSHOT, which it never can.
func ErrorCodes(err error) (code, extended int, ok bool) {
var se sqlite3.Error
if !errors.As(err, &se) {
return 0, 0, false
}
return int(se.Code), int(se.ExtendedCode), true
}
type statusLogger struct{ numPending int }
func (*statusLogger) Fatalf(format string, v ...any) { log.Fatal(fmt.Sprintf(format, v...)) }
func (l *statusLogger) Printf(format string, v ...any) {
if len(v) < 1 {
return
}
if v0, ok := v[0].(string); !ok {
return
} else if v0 == "Pending" {
l.numPending++
}
}
func hasPendingMigrations(ctx context.Context, db *sql.DB, folder string) bool {
l := &statusLogger{}
goose.SetLogger(l)
err := goose.StatusContext(ctx, db, folder)
if err != nil {
log.Fatal(ctx, "Failed to check for pending migrations", err)
}
return l.numPending > 0
}
func isSchemaEmpty(ctx context.Context, db *sql.DB) bool {
rows, err := db.QueryContext(ctx, "SELECT name FROM sqlite_master WHERE type='table' AND name='goose_db_version';") // nolint:rowserrcheck
if err != nil {
log.Fatal(ctx, "Database could not be opened!", err)
}
defer rows.Close()
return !rows.Next()
}
type logAdapter struct {
ctx context.Context
silent bool
}
func (l *logAdapter) Fatal(v ...any) {
log.Fatal(l.ctx, fmt.Sprint(v...))
}
func (l *logAdapter) Fatalf(format string, v ...any) {
log.Fatal(l.ctx, fmt.Sprintf(format, v...))
}
func (l *logAdapter) Print(v ...any) {
if !l.silent {
log.Info(l.ctx, fmt.Sprint(v...))
}
}
func (l *logAdapter) Println(v ...any) {
if !l.silent {
log.Info(l.ctx, fmt.Sprintln(v...))
}
}
func (l *logAdapter) Printf(format string, v ...any) {
if !l.silent {
log.Info(l.ctx, fmt.Sprintf(format, v...))
}
}