perf(db): keep query planner statistics trustworthy with full ANALYZE (#5740)

* perf(db): keep query planner statistics trustworthy with full ANALYZE

PRAGMA optimize's internal ANALYZE runs with a limited analysis budget
(~2000 rows) that writes wrong sqlite_stat1 entries for low-cardinality
indexes: on a 96K-track library it claimed (missing, library_id) narrows
to ~2000 rows when it matches the whole table. The planner then prefers
that index over the sort index and falls back to a full-table temp
B-tree sort per request, turning paginated song listings into
multi-second queries (reproduced at 5.5s on real hardware; ~90x slower
than with correct stats). Every index-creating migration re-triggered
the poisoning via the post-migration optimize, and the daily optimizer
could re-trigger it on large library changes. Setting analysis_limit on
the connection does not help: optimize ignores it.

Run a plain full ANALYZE instead: after migrations with schema changes,
and in db.Optimize (daily schedule and scan-end). Stats are stored in
the database file, so one connection suffices and the per-connection
pool loop is gone. The Optimize call at shutdown is removed: stats are
maintained at migration/scan/daily points, and an ANALYZE during
shutdown only delays it and races container stop timeouts.

* perf(db): drop startup PRAGMA optimize that re-poisons planner stats

The startup PRAGMA optimize=0x10002 runs SQLite's budget-limited internal
ANALYZE (bit 0x02), which writes truncated sqlite_stat1 rows for
low-cardinality indexes -- the exact statistics-poisoning this PR set out to
eliminate. Because DevOptimizeDB defaults to true, a restart with no pending
migrations would re-poison the planner until the next scan or daily Optimize.

Remove it: statistics are already refreshed with a full ANALYZE after
schema-changing migrations (Init) and via Optimize at scan-end and on the daily
schedule, so nothing on the startup path needs to touch them. Also clarify that
Optimize is a no-op unless DevOptimizeDB is enabled.

* chore(db): remove the DevOptimizeDB flag and skip Optimize on quick scans

The flag only gated the optimize/ANALYZE maintenance calls and there is
no reason to leave planner statistics unmaintained; the guards are gone
along with the flag. The scan-end Optimize now runs only after full
scans — quick scans barely move the statistics, and the daily schedule
covers drift.

* style(scanner): drop redundant comment in runOptimize

* chore(persistence): drop the no-op PRAGMA optimize from ScanEnd

Mask 0x10000 only selects candidate tables by size change; without the
0x02 action bit optimize does nothing (verified: sqlite_stat1 stays
stale after a 100x table growth). The scan-end statistics refresh is
db.Optimize's full ANALYZE, and the expression-collation-index concern
the old comment guarded against no longer applies.

* fix(scanner): run the post-scan ANALYZE in the server process

With the external scanner (the default), the scan pipeline runs in a
subprocess, so its ANALYZE was invisible to the server: SQLite loads
sqlite_stat1 into the process's shared schema cache, and an ANALYZE from
another process does not refresh it — verified with the production DSN
that even brand-new pool connections keep planning with the old
statistics until the server restarts. An in-process ANALYZE, by
contrast, is immediately visible to every pooled connection through the
same shared cache.

Move the full-scan Optimize from the scanner pipeline to the scan
controller, which always runs in the server process.

* fix(scanner): honor promoted full scans in the optimize gate

A quick scan resuming an interrupted full scan is promoted inside the
scanner (possibly in a subprocess); mirror the promotion in the
controller so the post-scan ANALYZE isn't skipped.

* refactor: apply cleanup review findings

- drop forceFullRescan's inline ANALYZE: Init already runs a full
  ANALYZE after any migration batch with schema changes, so upgrades
  including a full-rescan migration analyzed the whole DB twice
- resumingFullScan uses a filtered CountAll instead of fetching and
  scanning all libraries
- document why CallScan (CLI) deliberately skips the post-scan Optimize

* perf(db): make planner analysis maintenance resilient

Check analysis freshness every 30 minutes and refresh statistics when the last successful run is over 24 hours old or a scan marked them pending. Persist successful analysis state, retry skipped or failed maintenance, coordinate checks with scans, and cover standalone CLI full scans.

* perf(db): avoid analyzing routine quick-scan changes

Reserve pending analysis for full scans, unscanned libraries, and retry state. Incremental quick scans now rely on the 24-hour freshness window instead of triggering a full ANALYZE at the next maintenance check.

* fix(scan): analyze resumed full scans in CLI

* fix(db): back off failed analysis retries

* feat(db): allow disabling scheduled analysis

* test(db): remove redundant analysis coverage

* refactor(db): split ANALYZE maintenance into optimize.go and dedupe call sites

- move query-planner statistics code from db.go to its own optimize.go
  (and matching optimize_test.go)
- log ANALYZE elapsed time inside Optimize/OptimizeIfNeeded instead of
  repeating the timing block at every call site
- drop the LastDBAnalyzeAttemptAt write on success: it is only read
  while failures >= 1, and every failure rewrites it first
- extract runPostScanAnalysis (cmd) and anyIncludedLibrary (scanner)
  helpers
This commit is contained in:
Deluan Quintão 2026-07-13 12:04:29 -04:00 committed by GitHub
parent 4998ac2c59
commit cc315dcc8c
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
18 changed files with 673 additions and 130 deletions

View File

@ -86,7 +86,7 @@ func runNavidrome(ctx context.Context) {
g.Go(startPlaybackServer(ctx))
g.Go(schedulePeriodicBackup(ctx))
g.Go(startInsightsCollector(ctx))
g.Go(scheduleDBOptimizer(ctx))
g.Go(scheduleDBAnalyzer(ctx))
g.Go(startPluginManager(ctx))
g.Go(runInitialScan(ctx))
if conf.Server.Scanner.Enabled {
@ -275,16 +275,24 @@ func schedulePeriodicBackup(ctx context.Context) func() error {
}
}
func scheduleDBOptimizer(ctx context.Context) func() error {
func scheduleDBAnalyzer(ctx context.Context) func() error {
return func() error {
log.Info(ctx, "Scheduling DB optimizer", "schedule", consts.OptimizeDBSchedule)
if !conf.Server.EnableScheduledDBAnalyze {
log.Info(ctx, "Scheduled DB analysis is DISABLED")
return nil
}
log.Info(ctx, "Scheduling DB analysis check", "schedule", consts.DBAnalyzeCheckSchedule)
schedulerInstance := scheduler.GetInstance()
_, err := schedulerInstance.Add(consts.OptimizeDBSchedule, func() {
if scanner.IsScanning() {
log.Debug(ctx, "Skipping DB optimization because a scan is in progress")
_, err := schedulerInstance.Add(consts.DBAnalyzeCheckSchedule, func() {
release, ok := scanner.LockForMaintenance()
if !ok {
log.Debug(ctx, "Skipping DB analysis check because a scan is in progress")
return
}
db.Optimize(ctx)
defer release()
if _, err := db.OptimizeIfNeeded(ctx); err != nil {
log.Error(ctx, "Error analyzing DB", err)
}
})
return err
}

View File

@ -4,6 +4,7 @@ import (
"bufio"
"context"
"encoding/gob"
"errors"
"fmt"
"os"
"strings"
@ -43,15 +44,20 @@ var scanCmd = &cobra.Command{
},
}
func trackScanInteractively(ctx context.Context, progress <-chan *scanner.ProgressInfo) {
func trackScanInteractively(ctx context.Context, progress <-chan *scanner.ProgressInfo) (bool, error) {
var changesDetected bool
var scanErrors []error
for status := range pl.ReadOrDone(ctx, progress) {
if status.Warning != "" {
log.Warn(ctx, "Scan warning", "error", status.Warning)
}
if status.Error != "" {
log.Error(ctx, "Scan error", "error", status.Error)
scanErrors = append(scanErrors, errors.New(status.Error))
}
if status.ChangesDetected {
changesDetected = true
}
// Discard the progress status, we only care about errors
}
if fullScan {
@ -59,6 +65,7 @@ func trackScanInteractively(ctx context.Context, progress <-chan *scanner.Progre
} else {
log.Info("Finished rescan")
}
return changesDetected, errors.Join(scanErrors...)
}
func trackScanAsSubprocess(ctx context.Context, progress <-chan *scanner.ProgressInfo) {
@ -95,6 +102,16 @@ func runScanner(ctx context.Context) {
log.Info(ctx, "Scanning specific folders", "numTargets", len(scanTargets))
}
effectiveFullScan := fullScan
if !subprocess {
effectiveFullScan = scanner.EffectiveFullScan(ctx, ds, fullScan, scanTargets)
if effectiveFullScan {
if err := db.MarkOptimizePending(ctx); err != nil {
log.Error(ctx, "Error marking DB analysis pending", err)
}
}
}
progress, err := scanner.CallScan(ctx, ds, pls, fullScan, scanTargets)
if err != nil {
log.Fatal(ctx, "Failed to scan", err)
@ -104,7 +121,21 @@ func runScanner(ctx context.Context) {
if subprocess {
trackScanAsSubprocess(ctx, progress)
} else {
trackScanInteractively(ctx, progress)
changesDetected, scanErr := trackScanInteractively(ctx, progress)
runPostScanAnalysis(ctx, changesDetected, effectiveFullScan, scanErr)
}
}
func runPostScanAnalysis(ctx context.Context, changesDetected, effectiveFullScan bool, scanErr error) {
if changesDetected {
if err := db.MarkOptimizePending(ctx); err != nil {
log.Error(ctx, "Error marking DB analysis pending", err)
}
}
if effectiveFullScan && scanErr == nil {
if err := db.Optimize(ctx); err != nil {
log.Error(ctx, "Error analyzing DB", err)
}
}
}

View File

@ -1,14 +1,29 @@
package cmd
import (
"context"
"os"
"path/filepath"
"github.com/navidrome/navidrome/model"
"github.com/navidrome/navidrome/scanner"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
)
var _ = Describe("trackScanInteractively", func() {
It("reports changes and scan errors", func() {
progress := make(chan *scanner.ProgressInfo, 2)
progress <- &scanner.ProgressInfo{ChangesDetected: true}
progress <- &scanner.ProgressInfo{Error: "scan failed"}
close(progress)
changesDetected, err := trackScanInteractively(context.Background(), progress)
Expect(changesDetected).To(BeTrue())
Expect(err).To(MatchError("scan failed"))
})
})
var _ = Describe("readTargetsFromFile", func() {
var tempDir string

View File

@ -51,6 +51,7 @@ type configOptions struct {
EnableExternalServices bool
EnableM3UExternalAlbumArt bool
EnableInsightsCollector bool
EnableScheduledDBAnalyze bool
EnableMediaFileCoverArt bool
TranscodingCacheSize string
ImageCacheSize string
@ -147,7 +148,6 @@ type configOptions struct {
DevEnablePluginsInsights bool
DevPluginCompilationTimeout time.Duration
DevExternalArtistFetchMultiplier float64
DevOptimizeDB bool
DevPreserveUnicodeInExternalCalls bool
DevEnableMediaFileProbe bool
}
@ -800,6 +800,7 @@ func setViperDefaults() {
viper.SetDefault("defaultdownloadableshare", false)
viper.SetDefault("gatrackingid", "")
viper.SetDefault("enableinsightscollector", true)
viper.SetDefault("enablescheduleddbanalyze", true)
viper.SetDefault("enablelogredacting", true)
viper.SetDefault("authrequestlimit", 5)
viper.SetDefault("authwindowlength", 20*time.Second)
@ -891,7 +892,6 @@ func setViperDefaults() {
viper.SetDefault("devenablepluginsinsights", true)
viper.SetDefault("devplugincompilationtimeout", time.Minute)
viper.SetDefault("devexternalartistfetchmultiplier", 1.5)
viper.SetDefault("devoptimizedb", true)
viper.SetDefault("devpreserveunicodeinexternalcalls", false)
viper.SetDefault("devenablemediafileprobe", true)
}

View File

@ -58,6 +58,19 @@ var _ = Describe("Configuration", func() {
})
})
Describe("scheduled DB analysis", func() {
It("is enabled by default", func() {
conf.Load(true)
Expect(conf.Server.EnableScheduledDBAnalyze).To(BeTrue())
})
It("can be disabled", func() {
viper.Set("enablescheduleddbanalyze", false)
conf.Load(true)
Expect(conf.Server.EnableScheduledDBAnalyze).To(BeFalse())
})
})
Describe("ValidateURL", func() {
It("accepts a valid http URL", func() {
fn := conf.ValidateURL("TestOption", "http://example.com/path")

View File

@ -20,6 +20,10 @@ const (
LastScanErrorKey = "LastScanError"
LastScanTypeKey = "LastScanType"
LastScanStartTimeKey = "LastScanStartTime"
LastDBAnalyzeAtKey = "LastDBAnalyzeAt"
LastDBAnalyzeAttemptAtKey = "LastDBAnalyzeAttemptAt"
DBAnalyzePendingKey = "DBAnalyzePending"
DBAnalyzeFailureCountKey = "DBAnalyzeFailureCount"
UIAuthorizationHeader = "X-ND-Authorization"
UIClientUniqueIDHeader = "X-ND-Client-Unique-Id"
@ -28,7 +32,8 @@ const (
DefaultSessionTimeout = 48 * time.Hour
CookieExpiry = 365 * 24 * 3600 // One year
OptimizeDBSchedule = "@every 24h"
DBAnalyzeCheckSchedule = "@every 30m"
DBAnalyzeMaxAge = 24 * time.Hour
// DefaultEncryptionKey This is the encryption key used if none is specified in the `PasswordEncryptionKey` option
// Never ever change this! Or it will break all Navidrome installations that don't set the config option

View File

@ -223,6 +223,7 @@ var staticData = sync.OnceValue(func() insights.Data {
data.Config.ScanSchedule = conf.Server.Scanner.Schedule
data.Config.ScanWatcherWait = uint64(math.Trunc(conf.Server.Scanner.WatcherWait.Seconds()))
data.Config.ScanOnStartup = conf.Server.Scanner.ScanOnStartup
data.Config.EnableScheduledDBAnalyze = conf.Server.EnableScheduledDBAnalyze
data.Config.ReverseProxyConfigured = conf.Server.ExtAuth.TrustedSources != ""
data.Config.HasCustomPID = conf.Server.PID.Track != consts.DefaultTrackPID || conf.Server.PID.Album != consts.DefaultAlbumPID
data.Config.HasCustomTags = len(conf.Server.Tags) > 0

View File

@ -43,45 +43,46 @@ type Data struct {
FileSuffixes map[string]int64 `json:"fileSuffixes,omitempty"`
} `json:"library"`
Config struct {
LogLevel string `json:"logLevel,omitempty"`
LogFileConfigured bool `json:"logFileConfigured,omitempty"`
TLSConfigured bool `json:"tlsConfigured,omitempty"`
ScannerEnabled bool `json:"scannerEnabled,omitempty"`
ScannerExtractor string `json:"scannerExtractor,omitempty"`
ScanSchedule string `json:"scanSchedule,omitempty"`
ScanWatcherWait uint64 `json:"scanWatcherWait,omitempty"`
ScanOnStartup bool `json:"scanOnStartup,omitempty"`
TranscodingCacheSize string `json:"transcodingCacheSize,omitempty"`
ImageCacheSize string `json:"imageCacheSize,omitempty"`
EnableArtworkPrecache bool `json:"enableArtworkPrecache,omitempty"`
EnableDownloads bool `json:"enableDownloads,omitempty"`
EnableSharing bool `json:"enableSharing,omitempty"`
EnableStarRating bool `json:"enableStarRating,omitempty"`
EnableLastFM bool `json:"enableLastFM,omitempty"`
EnableListenBrainz bool `json:"enableListenBrainz,omitempty"`
EnableDeezer bool `json:"enableDeezer,omitempty"`
EnableMediaFileCoverArt bool `json:"enableMediaFileCoverArt,omitempty"`
EnableJukebox bool `json:"enableJukebox,omitempty"`
EnablePrometheus bool `json:"enablePrometheus,omitempty"`
EnableArtworkUpload bool `json:"enableArtworkUpload,omitempty"`
CoverArtQuality int `json:"coverArtQuality,omitempty"`
EnableWebPEncoding bool `json:"enableWebPEncoding,omitempty"`
UICoverArtSize int `json:"uiCoverArtSize,omitempty"`
EnableCoverAnimation bool `json:"enableCoverAnimation,omitempty"`
EnableNowPlaying bool `json:"enableNowPlaying,omitempty"`
SessionTimeout uint64 `json:"sessionTimeout,omitempty"`
SearchFullString bool `json:"searchFullString,omitempty"`
SearchBackend string `json:"searchBackend,omitempty"`
RecentlyAddedByModTime bool `json:"recentlyAddedByModTime,omitempty"`
PreferSortTags bool `json:"preferSortTags,omitempty"`
BackupSchedule string `json:"backupSchedule,omitempty"`
BackupCount int `json:"backupCount,omitempty"`
DevActivityPanel bool `json:"devActivityPanel,omitempty"`
DefaultBackgroundURLSet bool `json:"defaultBackgroundURL,omitempty"`
HasSmartPlaylists bool `json:"hasSmartPlaylists,omitempty"`
ReverseProxyConfigured bool `json:"reverseProxyConfigured,omitempty"`
HasCustomPID bool `json:"hasCustomPID,omitempty"`
HasCustomTags bool `json:"hasCustomTags,omitempty"`
LogLevel string `json:"logLevel,omitempty"`
LogFileConfigured bool `json:"logFileConfigured,omitempty"`
TLSConfigured bool `json:"tlsConfigured,omitempty"`
ScannerEnabled bool `json:"scannerEnabled,omitempty"`
ScannerExtractor string `json:"scannerExtractor,omitempty"`
ScanSchedule string `json:"scanSchedule,omitempty"`
ScanWatcherWait uint64 `json:"scanWatcherWait,omitempty"`
ScanOnStartup bool `json:"scanOnStartup,omitempty"`
EnableScheduledDBAnalyze bool `json:"enableScheduledDBAnalyze,omitempty"`
TranscodingCacheSize string `json:"transcodingCacheSize,omitempty"`
ImageCacheSize string `json:"imageCacheSize,omitempty"`
EnableArtworkPrecache bool `json:"enableArtworkPrecache,omitempty"`
EnableDownloads bool `json:"enableDownloads,omitempty"`
EnableSharing bool `json:"enableSharing,omitempty"`
EnableStarRating bool `json:"enableStarRating,omitempty"`
EnableLastFM bool `json:"enableLastFM,omitempty"`
EnableListenBrainz bool `json:"enableListenBrainz,omitempty"`
EnableDeezer bool `json:"enableDeezer,omitempty"`
EnableMediaFileCoverArt bool `json:"enableMediaFileCoverArt,omitempty"`
EnableJukebox bool `json:"enableJukebox,omitempty"`
EnablePrometheus bool `json:"enablePrometheus,omitempty"`
EnableArtworkUpload bool `json:"enableArtworkUpload,omitempty"`
CoverArtQuality int `json:"coverArtQuality,omitempty"`
EnableWebPEncoding bool `json:"enableWebPEncoding,omitempty"`
UICoverArtSize int `json:"uiCoverArtSize,omitempty"`
EnableCoverAnimation bool `json:"enableCoverAnimation,omitempty"`
EnableNowPlaying bool `json:"enableNowPlaying,omitempty"`
SessionTimeout uint64 `json:"sessionTimeout,omitempty"`
SearchFullString bool `json:"searchFullString,omitempty"`
SearchBackend string `json:"searchBackend,omitempty"`
RecentlyAddedByModTime bool `json:"recentlyAddedByModTime,omitempty"`
PreferSortTags bool `json:"preferSortTags,omitempty"`
BackupSchedule string `json:"backupSchedule,omitempty"`
BackupCount int `json:"backupCount,omitempty"`
DevActivityPanel bool `json:"devActivityPanel,omitempty"`
DefaultBackgroundURLSet bool `json:"defaultBackgroundURL,omitempty"`
HasSmartPlaylists bool `json:"hasSmartPlaylists,omitempty"`
ReverseProxyConfigured bool `json:"reverseProxyConfigured,omitempty"`
HasCustomPID bool `json:"hasCustomPID,omitempty"`
HasCustomTags bool `json:"hasCustomTags,omitempty"`
} `json:"config"`
Plugins map[string]PluginInfo `json:"plugins,omitempty"`
}

View File

@ -6,6 +6,7 @@ import (
"embed"
"fmt"
"runtime"
"time"
"github.com/mattn/go-sqlite3"
"github.com/navidrome/navidrome/conf"
@ -47,12 +48,6 @@ func Db() *sql.DB {
if err != nil {
log.Fatal("Error opening database", err)
}
if conf.Server.DevOptimizeDB {
_, err = db.Exec("PRAGMA optimize=0x10002")
if err != nil {
log.Error("Error applying PRAGMA optimize", err)
}
}
return db
})
}
@ -61,9 +56,6 @@ func Close(ctx context.Context) {
// Ignore cancellations when closing the DB
ctx = context.WithoutCancel(ctx)
// Run optimize before closing
Optimize(ctx)
log.Info(ctx, "Closing Database")
err := Db().Close()
if err != nil {
@ -102,11 +94,11 @@ func Init(ctx context.Context) func() {
log.Fatal(ctx, "Failed to apply new migrations", err)
}
if hasSchemaChanges && conf.Server.DevOptimizeDB {
log.Debug(ctx, "Applying PRAGMA optimize after schema changes")
_, err = db.ExecContext(ctx, "PRAGMA optimize")
if hasSchemaChanges {
log.Debug(ctx, "Running ANALYZE after schema changes")
err = optimizeAt(ctx, db, time.Now())
if err != nil {
log.Error(ctx, "Error applying PRAGMA optimize", err)
log.Error(ctx, "Error running ANALYZE", err)
}
}
@ -115,37 +107,6 @@ func Init(ctx context.Context) func() {
}
}
// Optimize runs PRAGMA optimize on each connection in the pool
func Optimize(ctx context.Context) {
if !conf.Server.DevOptimizeDB {
return
}
numConns := Db().Stats().OpenConnections
if numConns == 0 {
log.Debug(ctx, "No open connections to optimize")
return
}
log.Debug(ctx, "Optimizing open connections", "numConns", numConns)
var conns []*sql.Conn
for range numConns {
conn, err := Db().Conn(ctx)
conns = append(conns, conn)
if err != nil {
log.Error(ctx, "Error getting connection from pool", err)
continue
}
_, err = conn.ExecContext(ctx, "PRAGMA optimize;")
if err != nil {
log.Error(ctx, "Error running PRAGMA optimize", err)
}
}
// Return all connections to the Connection Pool
for _, conn := range conns {
conn.Close()
}
}
type statusLogger struct{ numPending int }
func (*statusLogger) Fatalf(format string, v ...any) { log.Fatal(fmt.Sprintf(format, v...)) }

View File

@ -2,6 +2,9 @@ package db
// Definitions for testing private methods
var (
IsSchemaEmpty = isSchemaEmpty
BackupPath = backupPath
IsSchemaEmpty = isSchemaEmpty
BackupPath = backupPath
OptimizeDBAt = optimizeAt
OptimizeDBIfNeeded = optimizeIfNeeded
RecordAnalyzeFailure = recordAnalyzeFailure
)

View File

@ -7,7 +7,6 @@ import (
"strings"
"sync"
"github.com/navidrome/navidrome/conf"
"github.com/navidrome/navidrome/consts"
)
@ -21,13 +20,6 @@ func notice(ctx context.Context, tx *sql.Tx, msg string) {
// Call this in migrations that requires a full rescan
func forceFullRescan(ctx context.Context, tx *sql.Tx) error {
// If a full scan is required, most probably the query optimizer is outdated, so we run `analyze`.
if conf.Server.DevOptimizeDB {
_, err := tx.ExecContext(ctx, `ANALYZE;`)
if err != nil {
return err
}
}
_, err := tx.ExecContext(ctx, fmt.Sprintf(`
INSERT OR REPLACE into property (id, value) values ('%s', '1');
`, consts.FullScanAfterMigrationFlagKey))

224
db/optimize.go Normal file
View File

@ -0,0 +1,224 @@
package db
import (
"context"
"database/sql"
"errors"
"fmt"
"strconv"
"sync"
"time"
"github.com/navidrome/navidrome/consts"
"github.com/navidrome/navidrome/log"
)
var analyzeMux sync.Mutex
// Optimize refreshes the query-planner statistics with a full ANALYZE. PRAGMA optimize is avoided
// because its limited analysis misestimates Navidrome's low-cardinality indexes.
func Optimize(ctx context.Context) error {
analyzeMux.Lock()
defer analyzeMux.Unlock()
start := time.Now()
if err := optimizeAt(ctx, Db(), start); err != nil {
return err
}
log.Info(ctx, "DB analysis complete", "elapsed", time.Since(start))
return nil
}
// OptimizeIfNeeded refreshes statistics when they are stale or a database-changing operation
// marked them for refresh.
func OptimizeIfNeeded(ctx context.Context) (bool, error) {
analyzeMux.Lock()
defer analyzeMux.Unlock()
start := time.Now()
ran, err := optimizeIfNeeded(ctx, Db(), start)
if err != nil || !ran {
return ran, err
}
log.Info(ctx, "DB analysis complete", "elapsed", time.Since(start))
return true, nil
}
func optimizeIfNeeded(ctx context.Context, db *sql.DB, now time.Time) (bool, error) {
due, err := optimizeDue(ctx, db, now)
if err != nil || !due {
return false, err
}
return true, optimizeAt(ctx, db, now)
}
func optimizeDue(ctx context.Context, db *sql.DB, now time.Time) (bool, error) {
backingOff, err := analyzeRetryBackoffActive(ctx, db, now)
if err != nil || backingOff {
return false, err
}
pending, found, err := getProperty(ctx, db, consts.DBAnalyzePendingKey)
if err != nil {
return false, err
}
if found && pending == "1" {
return true, nil
}
value, found, err := getProperty(ctx, db, consts.LastDBAnalyzeAtKey)
if err != nil {
return false, err
}
if !found {
return true, nil
}
lastAnalyze, valid := parseAnalyzeTime(value)
if !valid || lastAnalyze.After(now) {
return true, nil
}
return now.Sub(lastAnalyze) >= consts.DBAnalyzeMaxAge, nil
}
func parseAnalyzeTime(value string) (time.Time, bool) {
parsed, err := time.Parse(time.RFC3339Nano, value)
return parsed, err == nil
}
func analyzeRetryBackoffActive(ctx context.Context, db *sql.DB, now time.Time) (bool, error) {
value, found, err := getProperty(ctx, db, consts.DBAnalyzeFailureCountKey)
if err != nil || !found {
return false, err
}
failures, _ := strconv.Atoi(value)
if failures < 1 {
return false, nil
}
value, found, err = getProperty(ctx, db, consts.LastDBAnalyzeAttemptAtKey)
if err != nil || !found {
return false, err
}
lastAttempt, valid := parseAnalyzeTime(value)
if !valid || lastAttempt.After(now) {
return false, nil
}
return now.Sub(lastAttempt) < analyzeRetryDelay(failures), nil
}
func analyzeRetryDelay(failures int) time.Duration {
switch failures {
case 1:
return 30 * time.Minute
case 2:
return time.Hour
case 3:
return 2 * time.Hour
default:
return 24 * time.Hour
}
}
// MarkOptimizePending requests a statistics refresh on the next scheduled maintenance check.
func MarkOptimizePending(ctx context.Context) error {
analyzeMux.Lock()
defer analyzeMux.Unlock()
return markOptimizePending(ctx, Db())
}
func markOptimizePending(ctx context.Context, db *sql.DB) error {
return putProperty(ctx, db, consts.DBAnalyzePendingKey, "1")
}
func optimizeAt(ctx context.Context, db *sql.DB, now time.Time) error {
if err := markOptimizePending(ctx, db); err != nil {
return recordAnalyzeError(ctx, db, now, fmt.Errorf("marking ANALYZE pending: %w", err))
}
log.Debug(ctx, "Refreshing query planner statistics")
_, err := db.ExecContext(ctx, "ANALYZE")
if err != nil {
return recordAnalyzeError(ctx, db, now, fmt.Errorf("running ANALYZE: %w", err))
}
if err = recordAnalyzeSuccess(ctx, db, now); err != nil {
return recordAnalyzeError(ctx, db, now, err)
}
return nil
}
func recordAnalyzeSuccess(ctx context.Context, db *sql.DB, now time.Time) error {
tx, err := db.BeginTx(ctx, nil)
if err != nil {
return fmt.Errorf("recording ANALYZE time: %w", err)
}
defer func() { _ = tx.Rollback() }()
if err = putProperty(ctx, tx, consts.LastDBAnalyzeAtKey, now.UTC().Format(time.RFC3339Nano)); err != nil {
return fmt.Errorf("recording ANALYZE time: %w", err)
}
if err = putProperty(ctx, tx, consts.DBAnalyzePendingKey, "0"); err != nil {
return fmt.Errorf("clearing pending ANALYZE: %w", err)
}
if err = putProperty(ctx, tx, consts.DBAnalyzeFailureCountKey, "0"); err != nil {
return fmt.Errorf("clearing ANALYZE failure count: %w", err)
}
if err = tx.Commit(); err != nil {
return fmt.Errorf("recording ANALYZE state: %w", err)
}
return nil
}
func recordAnalyzeError(ctx context.Context, db *sql.DB, now time.Time, analyzeErr error) error {
if err := recordAnalyzeFailure(ctx, db, now); err != nil {
return errors.Join(analyzeErr, fmt.Errorf("recording ANALYZE failure: %w", err))
}
return analyzeErr
}
func recordAnalyzeFailure(ctx context.Context, db *sql.DB, now time.Time) error {
tx, err := db.BeginTx(ctx, nil)
if err != nil {
return err
}
defer func() { _ = tx.Rollback() }()
value, found, err := getProperty(ctx, tx, consts.DBAnalyzeFailureCountKey)
if err != nil {
return err
}
failures := 0
if found {
failures, _ = strconv.Atoi(value)
failures = max(failures, 0)
}
if err = putProperty(ctx, tx, consts.DBAnalyzePendingKey, "1"); err != nil {
return err
}
if err = putProperty(ctx, tx, consts.DBAnalyzeFailureCountKey, strconv.Itoa(failures+1)); err != nil {
return err
}
if err = putProperty(ctx, tx, consts.LastDBAnalyzeAttemptAtKey, now.UTC().Format(time.RFC3339Nano)); err != nil {
return err
}
return tx.Commit()
}
type sqlExecer interface {
ExecContext(context.Context, string, ...any) (sql.Result, error)
}
type sqlQueryer interface {
QueryRowContext(context.Context, string, ...any) *sql.Row
}
func putProperty(ctx context.Context, db sqlExecer, key, value string) error {
_, err := db.ExecContext(ctx, `insert into property(id, value) values(?, ?)
on conflict(id) do update set value=excluded.value`, key, value)
return err
}
func getProperty(ctx context.Context, db sqlQueryer, key string) (string, bool, error) {
var value string
err := db.QueryRowContext(ctx, "select value from property where id=?", key).Scan(&value)
if errors.Is(err, sql.ErrNoRows) {
return "", false, nil
}
return value, err == nil, err
}

162
db/optimize_test.go Normal file
View File

@ -0,0 +1,162 @@
package db_test
import (
"context"
"database/sql"
"time"
"github.com/navidrome/navidrome/consts"
"github.com/navidrome/navidrome/db"
. "github.com/onsi/ginkgo/v2"
. "github.com/onsi/gomega"
)
var _ = Describe("Optimize", func() {
var (
ctx context.Context
database *sql.DB
now time.Time
)
BeforeEach(func() {
ctx = context.Background()
now = time.Date(2026, time.July, 9, 12, 0, 0, 0, time.UTC)
var err error
database, err = sql.Open(db.Dialect, "file::memory:")
Expect(err).ToNot(HaveOccurred())
DeferCleanup(database.Close)
_, err = database.Exec(`create table property(
id varchar(255) primary key,
value varchar(255) not null default ''
)`)
Expect(err).ToNot(HaveOccurred())
_, err = database.Exec("create table analyze_probe(id integer primary key, flag int)")
Expect(err).ToNot(HaveOccurred())
_, err = database.Exec(`insert into analyze_probe(flag)
with recursive s(x) as (select 1 union all select x+1 from s where x < 3000)
select 0 from s`)
Expect(err).ToNot(HaveOccurred())
_, err = database.Exec("create index probe_flag on analyze_probe(flag)")
Expect(err).ToNot(HaveOccurred())
_, err = database.Exec("analyze")
Expect(err).ToNot(HaveOccurred())
})
putProperty := func(key, value string) {
_, err := database.Exec(`insert into property(id, value) values(?, ?)
on conflict(id) do update set value=excluded.value`, key, value)
Expect(err).ToNot(HaveOccurred())
}
getProperty := func(key string) string {
var value string
Expect(database.QueryRow("select value from property where id=?", key).Scan(&value)).To(Succeed())
return value
}
poisonStats := func() {
_, err := database.Exec("update sqlite_stat1 set stat='3000 50' where idx='probe_flag'")
Expect(err).ToNot(HaveOccurred())
}
It("replaces poisoned planner statistics with full-quality ones", func() {
poisonStats()
putProperty(consts.DBAnalyzePendingKey, "1")
Expect(db.OptimizeDBAt(ctx, database, now)).To(Succeed())
var stat string
err := database.QueryRow("select stat from sqlite_stat1 where idx='probe_flag'").Scan(&stat)
Expect(err).ToNot(HaveOccurred())
// A full ANALYZE sees all 3000 rows share one value: avg rows per key = row count.
Expect(stat).To(Equal("3000 3000"))
Expect(getProperty(consts.LastDBAnalyzeAtKey)).To(Equal(now.Format(time.RFC3339Nano)))
Expect(getProperty(consts.DBAnalyzePendingKey)).To(Equal("0"))
})
It("runs when no previous analysis was recorded", func() {
ran, err := db.OptimizeDBIfNeeded(ctx, database, now)
Expect(err).ToNot(HaveOccurred())
Expect(ran).To(BeTrue())
Expect(getProperty(consts.LastDBAnalyzeAtKey)).To(Equal(now.Format(time.RFC3339Nano)))
})
It("skips a recent analysis when no refresh is pending", func() {
lastAnalyze := now.Add(-23 * time.Hour)
putProperty(consts.LastDBAnalyzeAtKey, lastAnalyze.Format(time.RFC3339Nano))
putProperty(consts.DBAnalyzePendingKey, "0")
poisonStats()
ran, err := db.OptimizeDBIfNeeded(ctx, database, now)
Expect(err).ToNot(HaveOccurred())
Expect(ran).To(BeFalse())
Expect(getProperty(consts.LastDBAnalyzeAtKey)).To(Equal(lastAnalyze.Format(time.RFC3339Nano)))
var stat string
Expect(database.QueryRow("select stat from sqlite_stat1 where idx='probe_flag'").Scan(&stat)).To(Succeed())
Expect(stat).To(Equal("3000 50"))
})
It("runs when the previous analysis is stale", func() {
putProperty(consts.LastDBAnalyzeAtKey, now.Add(-consts.DBAnalyzeMaxAge).Format(time.RFC3339Nano))
putProperty(consts.DBAnalyzePendingKey, "0")
ran, err := db.OptimizeDBIfNeeded(ctx, database, now)
Expect(err).ToNot(HaveOccurred())
Expect(ran).To(BeTrue())
Expect(getProperty(consts.LastDBAnalyzeAtKey)).To(Equal(now.Format(time.RFC3339Nano)))
})
It("runs when a refresh is pending even if the previous analysis is recent", func() {
putProperty(consts.LastDBAnalyzeAtKey, now.Format(time.RFC3339Nano))
putProperty(consts.DBAnalyzePendingKey, "1")
ran, err := db.OptimizeDBIfNeeded(ctx, database, now.Add(time.Hour))
Expect(err).ToNot(HaveOccurred())
Expect(ran).To(BeTrue())
Expect(getProperty(consts.DBAnalyzePendingKey)).To(Equal("0"))
})
DescribeTable("backs off after consecutive analysis failures",
func(failures string, retryDelay time.Duration) {
putProperty(consts.DBAnalyzePendingKey, "1")
putProperty(consts.DBAnalyzeFailureCountKey, failures)
putProperty(consts.LastDBAnalyzeAttemptAtKey, now.Format(time.RFC3339Nano))
ran, err := db.OptimizeDBIfNeeded(ctx, database, now.Add(retryDelay-time.Nanosecond))
Expect(err).ToNot(HaveOccurred())
Expect(ran).To(BeFalse())
ran, err = db.OptimizeDBIfNeeded(ctx, database, now.Add(retryDelay))
Expect(err).ToNot(HaveOccurred())
Expect(ran).To(BeTrue())
Expect(getProperty(consts.DBAnalyzeFailureCountKey)).To(Equal("0"))
Expect(getProperty(consts.DBAnalyzePendingKey)).To(Equal("0"))
},
Entry("for 30 minutes after the first failure", "1", 30*time.Minute),
Entry("for one hour after the second failure", "2", time.Hour),
Entry("for two hours after the third failure", "3", 2*time.Hour),
Entry("for 24 hours after the fourth failure", "4", 24*time.Hour),
)
It("records consecutive analysis failures", func() {
putProperty(consts.DBAnalyzeFailureCountKey, "2")
Expect(db.RecordAnalyzeFailure(ctx, database, now)).To(Succeed())
Expect(getProperty(consts.DBAnalyzeFailureCountKey)).To(Equal("3"))
Expect(getProperty(consts.LastDBAnalyzeAttemptAtKey)).To(Equal(now.Format(time.RFC3339Nano)))
Expect(getProperty(consts.DBAnalyzePendingKey)).To(Equal("1"))
})
It("does not record success when analysis fails", func() {
lastAnalyze := now.Add(-48 * time.Hour).Format(time.RFC3339Nano)
putProperty(consts.LastDBAnalyzeAtKey, lastAnalyze)
canceledCtx, cancel := context.WithCancel(ctx)
cancel()
Expect(db.OptimizeDBAt(canceledCtx, database, now)).To(MatchError(ContainSubstring("context canceled")))
Expect(getProperty(consts.LastDBAnalyzeAtKey)).To(Equal(lastAnalyze))
})
})

View File

@ -173,15 +173,6 @@ func (r *libraryRepository) ScanEnd(id int) error {
Set("last_scan_started_at", time.Time{}).
Where(Eq{"id": id})
_, err := r.executeSQL(sq)
if err != nil {
return err
}
// https://www.sqlite.org/pragma.html#pragma_optimize
// Use mask 0x10000 to check table sizes without running ANALYZE
// Running ANALYZE can cause query planner issues with expression-based collation indexes
if conf.Server.DevOptimizeDB {
_, err = r.executeSQL(Expr("PRAGMA optimize=0x10000;"))
}
return err
}

View File

@ -4,6 +4,8 @@ import (
"context"
"errors"
"fmt"
"slices"
"sync"
"sync/atomic"
"time"
@ -13,6 +15,7 @@ import (
"github.com/navidrome/navidrome/core/auth"
"github.com/navidrome/navidrome/core/metrics"
"github.com/navidrome/navidrome/core/playlists"
"github.com/navidrome/navidrome/db"
"github.com/navidrome/navidrome/log"
"github.com/navidrome/navidrome/model"
"github.com/navidrome/navidrome/model/request"
@ -211,6 +214,16 @@ func (s *controller) ScanFolders(requestCtx context.Context, fullScan bool, targ
ctx := request.AddValues(s.rootCtx, requestCtx)
ctx = auth.WithAdminUser(ctx, s.ds)
// A quick scan is promoted to a full one when it resumes an interrupted full scan; that happens
// inside the scanner (possibly in a subprocess), so mirror it here for the analysis gate. Must
// be read before the scan: ScanEnd clears the flag.
effectiveFullScan := EffectiveFullScan(ctx, s.ds, fullScan, targets)
if effectiveFullScan || s.includesUnscannedLibrary(ctx, targets) {
if err := db.MarkOptimizePending(ctx); err != nil {
log.Error(ctx, "Scanner: Error marking DB analysis pending", err)
}
}
// Send the initial scan status event
s.sendMessage(ctx, &events.ScanStatus{Scanning: true, Count: 0, FolderCount: 0})
progress := make(chan *ProgressInfo, 100)
@ -229,6 +242,15 @@ func (s *controller) ScanFolders(requestCtx context.Context, fullScan bool, targ
if scanError != nil {
_ = s.ds.Property(ctx).Put(consts.LastScanErrorKey, scanError.Error())
}
// Refresh the query-planner statistics after a successful full scan. This must run in the
// server process: with the external scanner, an ANALYZE in the subprocess is invisible to the
// server's pooled connections; their shared schema cache keeps the old statistics until the
// process restarts.
if effectiveFullScan && scanError == nil {
if err := db.Optimize(ctx); err != nil {
log.Error(ctx, "Scanner: Error analyzing DB", err)
}
}
// If changes were detected, send a refresh event to all clients
if s.changesDetected {
log.Debug(ctx, "Library changes imported. Sending refresh event")
@ -255,18 +277,73 @@ func (s *controller) ScanFolders(requestCtx context.Context, fullScan bool, targ
// This is a global variable that is used to prevent multiple scans from running at the same time.
// "There can be only one" - https://youtu.be/sqcLjcSloXs?si=VlsjEOjTJZ68zIyg
var running atomic.Bool
var (
running atomic.Bool
scanMaintenanceMux sync.Mutex
)
func lockScan(ctx context.Context) (func(), error) {
if !running.CompareAndSwap(false, true) {
log.Debug(ctx, "Scanner already running, ignoring request")
return func() {}, ErrAlreadyScanning
}
scanMaintenanceMux.Lock()
return func() {
scanMaintenanceMux.Unlock()
running.Store(false)
}, nil
}
// LockForMaintenance prevents a scan from starting while database maintenance is running.
func LockForMaintenance() (func(), bool) {
if !scanMaintenanceMux.TryLock() {
return func() {}, false
}
if running.Load() {
scanMaintenanceMux.Unlock()
return func() {}, false
}
return scanMaintenanceMux.Unlock, true
}
// EffectiveFullScan reports whether a scan was requested as full or will resume an interrupted
// full scan in one of the included libraries.
func EffectiveFullScan(ctx context.Context, ds model.DataStore, fullScan bool, targets []model.ScanTarget) bool {
if fullScan {
return true
}
return anyIncludedLibrary(ctx, ds, targets, func(library model.Library) bool {
return library.FullScanInProgress
})
}
func (s *controller) includesUnscannedLibrary(ctx context.Context, targets []model.ScanTarget) bool {
return anyIncludedLibrary(ctx, s.ds, targets, func(library model.Library) bool {
return library.LastScanAt.IsZero()
})
}
// anyIncludedLibrary reports whether any library included in the scan (all of them when targets is
// empty) matches pred.
func anyIncludedLibrary(ctx context.Context, ds model.DataStore, targets []model.ScanTarget, pred func(model.Library) bool) bool {
libraries, err := ds.Library(ctx).GetAll()
if err != nil {
return false
}
if len(targets) == 0 {
return slices.ContainsFunc(libraries, pred)
}
targeted := make(map[int]struct{}, len(targets))
for _, target := range targets {
targeted[target.LibraryID] = struct{}{}
}
return slices.ContainsFunc(libraries, func(library model.Library) bool {
_, ok := targeted[library.ID]
return ok && pred(library)
})
}
func (s *controller) trackProgress(ctx context.Context, progress <-chan *ProgressInfo) ([]string, error) {
s.count.Store(0)
s.folderCount.Store(0)

View File

@ -55,3 +55,41 @@ var _ = Describe("Controller", func() {
})
})
})
var _ = Describe("LockForMaintenance", func() {
It("allows only one database maintenance operation at a time", func() {
release, ok := scanner.LockForMaintenance()
Expect(ok).To(BeTrue())
DeferCleanup(release)
_, ok = scanner.LockForMaintenance()
Expect(ok).To(BeFalse())
})
})
var _ = Describe("EffectiveFullScan", func() {
var ds *tests.MockDataStore
BeforeEach(func() {
libraries := &tests.MockLibraryRepo{}
libraries.SetData(model.Libraries{
{ID: 1, FullScanInProgress: true},
{ID: 2},
})
ds = &tests.MockDataStore{MockedLibrary: libraries}
})
It("detects an interrupted full scan in a targeted library", func() {
targets := []model.ScanTarget{{LibraryID: 1, FolderPath: "."}}
Expect(scanner.EffectiveFullScan(context.Background(), ds, false, targets)).To(BeTrue())
})
It("detects an interrupted full scan when scanning all libraries", func() {
Expect(scanner.EffectiveFullScan(context.Background(), ds, false, nil)).To(BeTrue())
})
It("ignores interrupted full scans in untargeted libraries", func() {
targets := []model.ScanTarget{{LibraryID: 2, FolderPath: "."}}
Expect(scanner.EffectiveFullScan(context.Background(), ds, false, targets)).To(BeFalse())
})
})

View File

@ -13,7 +13,6 @@ import (
"github.com/navidrome/navidrome/consts"
"github.com/navidrome/navidrome/core/artwork"
"github.com/navidrome/navidrome/core/playlists"
"github.com/navidrome/navidrome/db"
"github.com/navidrome/navidrome/log"
"github.com/navidrome/navidrome/model"
"github.com/navidrome/navidrome/utils/run"
@ -161,9 +160,6 @@ func (s *scannerImpl) scanFolders(ctx context.Context, fullScan bool, targets []
// Update last_scan_completed_at for all libraries
s.runUpdateLibraries(ctx, &state),
// Optimize DB
s.runOptimize(ctx),
)
if err != nil {
log.Error(ctx, "Scanner: Finished with error", "duration", time.Since(startTime), err)
@ -280,15 +276,6 @@ func (s *scannerImpl) runRefreshStats(ctx context.Context, state *scanState) fun
}
}
func (s *scannerImpl) runOptimize(ctx context.Context) func() error {
return func() error {
start := time.Now()
db.Optimize(ctx)
log.Debug(ctx, "Scanner: Optimized DB", "elapsed", time.Since(start))
return nil
}
}
func (s *scannerImpl) runUpdateLibraries(ctx context.Context, state *scanState) func() error {
return func() error {
start := time.Now()

View File

@ -4,10 +4,12 @@ import (
"context"
"path/filepath"
"testing/fstest"
"time"
"github.com/Masterminds/squirrel"
"github.com/navidrome/navidrome/conf"
"github.com/navidrome/navidrome/conf/configtest"
"github.com/navidrome/navidrome/consts"
"github.com/navidrome/navidrome/core"
"github.com/navidrome/navidrome/core/artwork"
"github.com/navidrome/navidrome/core/metrics"
@ -80,7 +82,7 @@ var _ = Describe("ScanFolders", Ordered, func() {
rock := template(_t{"albumartist": "Rock Artist", "album": "Rock Album"})
jazz := template(_t{"albumartist": "Jazz Artist", "album": "Jazz Album"})
pop := template(_t{"albumartist": "Pop Artist", "album": "Pop Album"})
createFS(fstest.MapFS{
fsys = createFS(fstest.MapFS{
"rock/track1.mp3": rock(track(1, "Rock Track 1")),
"rock/track2.mp3": rock(track(2, "Rock Track 2")),
"rock/subdir/track3.mp3": rock(track(3, "Rock Track 3")),
@ -122,6 +124,38 @@ var _ = Describe("ScanFolders", Ordered, func() {
// Verify files in the pop folder were NOT scanned
Expect(paths).ToNot(ContainElement("pop/track6.mp3"))
Expect(ds.Property(ctx).Get(consts.DBAnalyzePendingKey)).To(Equal("1"))
})
})
Describe("Planner statistics maintenance", func() {
It("does not mark routine quick-scan changes for immediate analysis", func() {
rock := template(_t{"albumartist": "Rock Artist", "album": "Rock Album"})
fsys = createFS(fstest.MapFS{
"rock/track1.mp3": rock(track(1, "Rock Track 1")),
})
_, err := s.ScanAll(ctx, true)
Expect(err).ToNot(HaveOccurred())
Expect(ds.Property(ctx).Get(consts.DBAnalyzePendingKey)).To(Equal("0"))
fsys.Add("rock/track2.mp3", rock(track(2, "Rock Track 2")), time.Now().Add(time.Second))
_, err = s.ScanAll(ctx, false)
Expect(err).ToNot(HaveOccurred())
Expect(ds.Property(ctx).Get(consts.DBAnalyzePendingKey)).To(Equal("0"))
})
It("does not treat an interrupted scan in an untargeted library as a full scan", func() {
otherLib := model.Library{ID: 2, Name: "Other Library", Path: "fake:///other"}
Expect(ds.Library(ctx).Put(&otherLib)).To(Succeed())
Expect(ds.Library(ctx).ScanBegin(lib.ID, true)).To(Succeed())
lastAnalyze := "2026-07-09T12:00:00Z"
Expect(ds.Property(ctx).Put(consts.LastDBAnalyzeAtKey, lastAnalyze)).To(Succeed())
Expect(ds.Property(ctx).Put(consts.DBAnalyzePendingKey, "0")).To(Succeed())
_, err := s.ScanFolders(ctx, false, []model.ScanTarget{{LibraryID: otherLib.ID, FolderPath: "."}})
Expect(err).ToNot(HaveOccurred())
Expect(ds.Property(ctx).Get(consts.LastDBAnalyzeAtKey)).To(Equal(lastAnalyze))
})
})