mirror of
https://github.com/navidrome/navidrome.git
synced 2026-07-30 16:56:22 -04:00
* 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
225 lines
6.2 KiB
Go
225 lines
6.2 KiB
Go
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
|
|
}
|