navidrome/core/metrics/insights.go
Deluan Quintão cc315dcc8c
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
2026-07-13 12:04:29 -04:00

340 lines
11 KiB
Go

package metrics
import (
"bytes"
"context"
"encoding/json"
"math"
"net/http"
"os"
"path/filepath"
"runtime"
"runtime/debug"
"sync"
"sync/atomic"
"time"
"github.com/Masterminds/squirrel"
"github.com/google/uuid"
"github.com/navidrome/navidrome/conf"
"github.com/navidrome/navidrome/consts"
"github.com/navidrome/navidrome/core/auth"
"github.com/navidrome/navidrome/core/metrics/insights"
"github.com/navidrome/navidrome/log"
"github.com/navidrome/navidrome/model"
"github.com/navidrome/navidrome/model/request"
"github.com/navidrome/navidrome/plugins"
"github.com/navidrome/navidrome/server/events"
"github.com/navidrome/navidrome/utils/singleton"
)
type Insights interface {
Run(ctx context.Context)
LastRun(ctx context.Context) (timestamp time.Time, success bool)
}
var (
insightsID string
)
type insightsCollector struct {
ds model.DataStore
lastRun atomic.Int64
lastStatus atomic.Bool
}
func GetInstance(ds model.DataStore) Insights {
return singleton.GetInstance(func() *insightsCollector {
id, err := ds.Property(context.TODO()).Get(consts.InsightsIDKey)
if err != nil {
log.Trace("Could not get Insights ID from DB. Creating one", err)
id = uuid.NewString()
err = ds.Property(context.TODO()).Put(consts.InsightsIDKey, id)
if err != nil {
log.Trace("Could not save Insights ID to DB", err)
}
}
insightsID = id
return &insightsCollector{ds: ds}
})
}
func (c *insightsCollector) Run(ctx context.Context) {
for {
// Refresh admin context on each iteration to handle cases where
// admin user wasn't available on previous runs
insightsCtx := auth.WithAdminUser(ctx, c.ds)
u, _ := request.UserFrom(insightsCtx)
if !u.IsAdmin {
log.Trace(insightsCtx, "No admin user available, skipping insights collection")
} else {
c.sendInsights(insightsCtx)
}
select {
case <-time.After(consts.InsightsUpdateInterval):
continue
case <-ctx.Done():
return
}
}
}
func (c *insightsCollector) LastRun(context.Context) (timestamp time.Time, success bool) {
t := c.lastRun.Load()
return time.UnixMilli(t), c.lastStatus.Load()
}
func (c *insightsCollector) sendInsights(ctx context.Context) {
count, err := c.ds.User(ctx).CountAll(model.QueryOptions{})
if err != nil {
log.Trace(ctx, "Could not check user count", err)
return
}
if count == 0 {
log.Trace(ctx, "No users found, skipping Insights data collection")
return
}
hc := &http.Client{
Timeout: consts.DefaultHttpClientTimeOut,
}
data := c.collect(ctx)
if data == nil {
return
}
body := bytes.NewReader(data)
req, err := http.NewRequestWithContext(ctx, "POST", consts.InsightsEndpoint, body)
if err != nil {
log.Trace(ctx, "Could not create Insights request", err)
return
}
req.Header.Set("Content-Type", "application/json")
resp, err := hc.Do(req) //nolint:gosec
if err != nil {
log.Trace(ctx, "Could not send Insights data", err)
return
}
log.Info(ctx, "Sent Insights data (for details see http://navidrome.org/docs/getting-started/insights", "data",
string(data), "server", consts.InsightsEndpoint, "status", resp.Status)
c.lastRun.Store(time.Now().UnixMilli())
c.lastStatus.Store(resp.StatusCode < 300)
resp.Body.Close()
}
func buildInfo() (map[string]string, string) {
bInfo := map[string]string{}
var version string
if info, ok := debug.ReadBuildInfo(); ok {
for _, setting := range info.Settings {
if setting.Value == "" {
continue
}
bInfo[setting.Key] = setting.Value
}
version = info.GoVersion
}
return bInfo, version
}
func getFSInfo(path string) *insights.FSInfo {
var info insights.FSInfo
// Normalize the path
absPath, err := filepath.Abs(path)
if err != nil {
return nil
}
absPath = filepath.Clean(absPath)
fsType, err := getFilesystemType(absPath)
if err != nil {
return nil
}
info.Type = fsType
return &info
}
var staticData = sync.OnceValue(func() insights.Data {
// Basic info
data := insights.Data{
InsightsID: insightsID,
Version: consts.Version,
}
// Build info
data.Build.Settings, data.Build.GoVersion = buildInfo()
data.OS.Containerized = consts.InContainer
// Install info
packageFilename := filepath.Join(conf.Server.DataFolder.String(), ".package")
packageFileData, err := os.ReadFile(packageFilename)
if err == nil {
data.OS.Package = string(packageFileData)
}
// OS info
data.OS.Type = runtime.GOOS
data.OS.Arch = runtime.GOARCH
data.OS.NumCPU = runtime.NumCPU()
data.OS.Version, data.OS.Distro = getOSVersion()
// FS info
data.FS.Music = getFSInfo(conf.Server.MusicFolder)
data.FS.Data = getFSInfo(conf.Server.DataFolder.String())
if conf.Server.CacheFolder.String() != "" {
data.FS.Cache = getFSInfo(conf.Server.CacheFolder.String())
}
if conf.Server.Backup.Path.String() != "" {
data.FS.Backup = getFSInfo(conf.Server.Backup.Path.String())
}
// Config info
data.Config.LogLevel = conf.Server.LogLevel
data.Config.LogFileConfigured = conf.Server.LogFile != ""
data.Config.TLSConfigured = conf.Server.TLSCert != "" && conf.Server.TLSKey != ""
data.Config.DefaultBackgroundURLSet = conf.Server.UILoginBackgroundURL == consts.DefaultUILoginBackgroundURL
data.Config.EnableArtworkPrecache = conf.Server.EnableArtworkPrecache
data.Config.EnableArtworkUpload = conf.Server.EnableArtworkUpload
data.Config.CoverArtQuality = conf.Server.CoverArtQuality
data.Config.EnableWebPEncoding = conf.Server.EnableWebPEncoding
data.Config.UICoverArtSize = conf.Server.UICoverArtSize
data.Config.EnableCoverAnimation = conf.Server.EnableCoverAnimation
data.Config.EnableNowPlaying = conf.Server.EnableNowPlaying
data.Config.EnableDownloads = conf.Server.EnableDownloads
data.Config.EnableSharing = conf.Server.EnableSharing
data.Config.EnableStarRating = conf.Server.EnableStarRating
data.Config.EnableLastFM = conf.Server.LastFM.Enabled && conf.Server.LastFM.ApiKey != "" && conf.Server.LastFM.Secret != ""
data.Config.EnableListenBrainz = conf.Server.ListenBrainz.Enabled
data.Config.EnableDeezer = conf.Server.Deezer.Enabled
data.Config.EnableMediaFileCoverArt = conf.Server.EnableMediaFileCoverArt
data.Config.EnableJukebox = conf.Server.Jukebox.Enabled
data.Config.EnablePrometheus = conf.Server.Prometheus.Enabled
data.Config.TranscodingCacheSize = conf.Server.TranscodingCacheSize
data.Config.ImageCacheSize = conf.Server.ImageCacheSize
data.Config.SessionTimeout = uint64(math.Trunc(conf.Server.SessionTimeout.Seconds()))
data.Config.SearchFullString = conf.Server.Search.FullString
data.Config.SearchBackend = conf.Server.Search.Backend
data.Config.RecentlyAddedByModTime = conf.Server.RecentlyAddedByModTime
data.Config.PreferSortTags = conf.Server.PreferSortTags
data.Config.BackupSchedule = conf.Server.Backup.Schedule
data.Config.BackupCount = conf.Server.Backup.Count
data.Config.DevActivityPanel = conf.Server.DevActivityPanel
data.Config.ScannerEnabled = conf.Server.Scanner.Enabled
data.Config.ScannerExtractor = conf.Server.Scanner.Extractor
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
return data
})
func (c *insightsCollector) collect(ctx context.Context) []byte {
data := staticData()
data.Uptime = time.Since(consts.ServerStart).Milliseconds() / 1000
// Library info
var err error
data.Library.Tracks, err = c.ds.MediaFile(ctx).CountAll()
if err != nil {
log.Trace(ctx, "Error reading tracks count", err)
}
data.Library.Albums, err = c.ds.Album(ctx).CountAll()
if err != nil {
log.Trace(ctx, "Error reading albums count", err)
}
data.Library.Artists, err = c.ds.Artist(ctx).CountAll()
if err != nil {
log.Trace(ctx, "Error reading artists count", err)
}
data.Library.Playlists, err = c.ds.Playlist(ctx).CountAll()
if err != nil {
log.Trace(ctx, "Error reading playlists count", err)
}
data.Library.Shares, err = c.ds.Share(ctx).CountAll()
if err != nil {
log.Trace(ctx, "Error reading shares count", err)
}
data.Library.Radios, err = c.ds.Radio(ctx).Count()
if err != nil {
log.Trace(ctx, "Error reading radios count", err)
}
data.Library.Libraries, err = c.ds.Library(ctx).CountAll()
if err != nil {
log.Trace(ctx, "Error reading libraries count", err)
}
data.Library.ActiveUsers, err = c.ds.User(ctx).CountAll(model.QueryOptions{
Filters: squirrel.Gt{"last_access_at": time.Now().Add(-7 * 24 * time.Hour)},
})
if err != nil {
log.Trace(ctx, "Error reading active users count", err)
}
data.Library.FileSuffixes, err = c.ds.MediaFile(ctx).CountBySuffix()
if err != nil {
log.Trace(ctx, "Error reading file suffixes count", err)
}
// Check for smart playlists
data.Config.HasSmartPlaylists, err = c.hasSmartPlaylists(ctx)
if err != nil {
log.Trace(ctx, "Error checking for smart playlists", err)
}
// Collect plugins if permitted and enabled
if conf.Server.DevEnablePluginsInsights && conf.Server.Plugins.Enabled {
data.Plugins = c.collectPlugins(ctx)
}
// Collect active players if permitted
if conf.Server.DevEnablePlayerInsights {
data.Library.ActivePlayers, err = c.ds.Player(ctx).CountByClient(model.QueryOptions{
Filters: squirrel.Gt{"last_seen": time.Now().Add(-7 * 24 * time.Hour)},
})
if err != nil {
log.Trace(ctx, "Error reading active players count", err)
}
}
// Memory info
var m runtime.MemStats
runtime.ReadMemStats(&m)
data.Mem.Alloc = m.Alloc
data.Mem.TotalAlloc = m.TotalAlloc
data.Mem.Sys = m.Sys
data.Mem.NumGC = m.NumGC
// Marshal to JSON
resp, err := json.Marshal(data)
if err != nil {
log.Trace(ctx, "Could not marshal Insights data", err)
return nil
}
return resp
}
// hasSmartPlaylists checks if there are any smart playlists (playlists with rules)
func (c *insightsCollector) hasSmartPlaylists(ctx context.Context) (bool, error) {
count, err := c.ds.Playlist(ctx).CountAll(model.QueryOptions{
Filters: squirrel.And{squirrel.NotEq{"rules": ""}, squirrel.NotEq{"rules": nil}},
})
return count > 0, err
}
// collectPlugins collects information about installed plugins
func (c *insightsCollector) collectPlugins(_ context.Context) map[string]insights.PluginInfo {
// TODO Fix import/inject cycles
manager := plugins.GetManager(c.ds, events.GetBroker(), nil)
info := manager.GetPluginInfo()
result := make(map[string]insights.PluginInfo, len(info))
for name, p := range info {
result[name] = insights.PluginInfo{
Name: p.Name,
Version: p.Version,
}
}
return result
}