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