From 56a36e4da48323d44826ff83f00036bc0d6a5380 Mon Sep 17 00:00:00 2001 From: Deluan Date: Wed, 29 Jul 2026 08:47:52 -0400 Subject: [PATCH] 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. --- db/db.go | 12 ++++++++++++ persistence/sql_base_repository.go | 13 ++++++++++--- 2 files changed, 22 insertions(+), 3 deletions(-) diff --git a/db/db.go b/db/db.go index 4ca996fe5..11a05b456 100644 --- a/db/db.go +++ b/db/db.go @@ -4,6 +4,7 @@ import ( "context" "database/sql" "embed" + "errors" "fmt" "time" @@ -106,6 +107,17 @@ func Init(ctx context.Context) func() { } } +// 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...)) } diff --git a/persistence/sql_base_repository.go b/persistence/sql_base_repository.go index d0cbb2946..33450fe9f 100644 --- a/persistence/sql_base_repository.go +++ b/persistence/sql_base_repository.go @@ -15,6 +15,7 @@ import ( . "github.com/Masterminds/squirrel" "github.com/deluan/rest" "github.com/navidrome/navidrome/conf" + "github.com/navidrome/navidrome/db" "github.com/navidrome/navidrome/log" "github.com/navidrome/navidrome/model" id2 "github.com/navidrome/navidrome/model/id" @@ -597,9 +598,15 @@ func (r sqlRepository) delete(cond Sqlizer) error { func (r sqlRepository) logSQL(sql string, args dbx.Params, err error, rowsAffected int64, start time.Time) { elapsed := time.Since(start) + fields := []any{r.ctx, "SQL: `" + sql + "`", "args", args, "rowsAffected", rowsAffected, "elapsedTime", elapsed} if err == nil || errors.Is(err, context.Canceled) { - log.Trace(r.ctx, "SQL: `"+sql+"`", "args", args, "rowsAffected", rowsAffected, "elapsedTime", elapsed, err) - } else { - log.Error(r.ctx, "SQL: `"+sql+"`", "args", args, "rowsAffected", rowsAffected, "elapsedTime", elapsed, err) + log.Trace(append(fields, err)...) + return } + // The result codes separate errors that share a message, notably SQLITE_BUSY from + // SQLITE_BUSY_SNAPSHOT, which no busy_timeout can retry. + if code, extended, ok := db.ErrorCodes(err); ok { + fields = append(fields, "sqliteCode", code, "sqliteExtended", extended) + } + log.Error(append(fields, err)...) }