minstrel/internal/wanted/search.go

package wanted

import (
	"context"
	"encoding/json"
	"errors"
	"log/slog"
	"strconv"
	"time"

	"github.com/jackc/pgx/v5/pgtype"
	"github.com/jackc/pgx/v5/pgxpool"

	"git.fabledsword.com/bvandeusen/minstrel/internal/acquire"
	"git.fabledsword.com/bvandeusen/minstrel/internal/catalogue"
	"git.fabledsword.com/bvandeusen/minstrel/internal/db/dbq"
	"git.fabledsword.com/bvandeusen/minstrel/internal/indexer"
	"git.fabledsword.com/bvandeusen/minstrel/internal/release"
)

// Searching for wants on a schedule (M502 #5521), ported from Fabled
// Librarian's internal/wanted. The schedule decides which wants and when;
// internal/acquire judges what a search finds and grabs.

// Search outcomes, matching wants_search_outcome_check.
const (
	OutcomeGrabbed = "grabbed"
	OutcomeWaiting = "waiting"
	OutcomeNothing = "nothing"
	OutcomeError   = "error"
)

const (
	// searchTick is how often the schedule looks for wants due; the
	// operator's setting is how long a want waits between searches.
	searchTick = 10 * time.Minute
	// searchWindow is how long one pass searches: most of a tick, so a pass
	// ends before the next begins.
	searchWindow = 9 * time.Minute
	// duePage bounds what one pass reads. The sources' pace is the real
	// limit; this caps a pass whose sources are all unpaced.
	duePage = 200
	// grabTries is how many grabbable releases one search tries in turn
	// when the first is refused for its files.
	grabTries = 3
	// passTimeout backs up the window for a call none of the clients'
	// own timeouts cover, such as a wedged database read.
	passTimeout = 15 * time.Minute
)

// ErrWantHeld: the want is already answered by the library.
var ErrWantHeld = errors.New("wanted: the library already holds this album")

// Searcher searches for wants and grabs what they need.
type Searcher struct {
	pool   *pgxpool.Pool
	cat    *catalogue.Service
	logger *slog.Logger
}

// NewSearcher returns a Searcher reading editions through cat (nil reads
// only what the catalogue already holds).
func NewSearcher(pool *pgxpool.Pool, cat *catalogue.Service, logger *slog.Logger) *Searcher {
	if logger == nil {
		logger = slog.Default()
	}
	return &Searcher{pool: pool, cat: cat, logger: logger}
}

// Report is one pass.
type Report struct {
	Looked  int `json:"looked"`
	Grabbed int `json:"grabbed"`
	Waiting int `json:"waiting"`
	Nothing int `json:"nothing"`
	Failed  int `json:"failed"`
	// Paced: the pass stopped because the next search would wait past its
	// window for a source's pace.
	Paced bool `json:"paced"`
	// Off: the schedule is switched off. Unconfigured: nothing to search
	// with. Both are states, not faults.
	Off          bool   `json:"off"`
	Unconfigured bool   `json:"unconfigured"`
	AutoGrab     bool   `json:"auto_grab"`
	Error        string `json:"error,omitempty"`
}

// Run searches every searchTick until ctx ends.
func (s *Searcher) Run(ctx context.Context) {
	ticker := time.NewTicker(searchTick)
	defer ticker.Stop()
	said := ""
	for {
		select {
		case <-ctx.Done():
			return
		case <-ticker.C:
		}
		rep := s.Pass(ctx)
		// A pass that searched is always logged; an idle one only when the
		// schedule's state changes, so the log says once why it is quiet.
		if state := rep.state(); rep.Looked > 0 || rep.Error != "" || state != said {
			s.logger.Info("wanted: search pass", "state", state, "looked", rep.Looked,
				"grabbed", rep.Grabbed, "waiting", rep.Waiting, "nothing", rep.Nothing,
				"failed", rep.Failed, "paced", rep.Paced, "error", rep.Error)
			said = state
		}
	}
}

// state names why a pass did what it did: off, unconfigured, failed,
// idle (nothing was due) or searched.
func (r Report) state() string {
	switch {
	case r.Off:
		return "off"
	case r.Unconfigured:
		return "unconfigured"
	case r.Error != "":
		return "failed"
	case r.Looked == 0:
		return "idle"
	}
	return "searched"
}

// Pass searches for the wants due, paced by the sources, until the window
// closes, and records what it did.
func (s *Searcher) Pass(ctx context.Context) Report {
	rep := s.pass(ctx)
	if body, err := json.Marshal(rep); err == nil {
		if err := dbq.New(s.pool).RecordSearchPass(ctx, body); err != nil && ctx.Err() == nil {
			s.logger.Warn("wanted: record search pass", "err", err)
		}
	}
	return rep
}

func (s *Searcher) pass(ctx context.Context) Report {
	var rep Report
	ctx, cancel := context.WithTimeout(ctx, passTimeout)
	defer cancel()
	svc, settings, err := acquire.Build(ctx, s.pool)
	if err != nil {
		rep.Error = indexer.FirstLine(err.Error())
		return rep
	}
	rep.AutoGrab = settings.AutoGrab
	switch {
	case settings.SearchIntervalHours <= 0:
		rep.Off = true
		return rep
	case svc.Search == nil:
		rep.Unconfigured = true
		return rep
	}
	deadline := time.Now().Add(searchWindow)
	due, err := dbq.New(s.pool).ListWantsDueForSearch(ctx, dbq.ListWantsDueForSearchParams{
		Hours: settings.SearchIntervalHours, MaxRows: duePage,
	})
	if err != nil {
		rep.Error = indexer.FirstLine(err.Error())
		return rep
	}
	for _, row := range due {
		if !svc.Ready(ctx, deadline) {
			rep.Paced = ctx.Err() == nil
			return rep
		}
		want := s.wantFor(ctx, row.ID, row.ArtistName, row.Title, row.PrimaryType, row.SecondaryTypes,
			row.FirstReleaseDate, row.ReleaseGroupMbid)
		out := s.one(ctx, svc, want, settings.AutoGrab)
		rep.Looked++
		switch out.Outcome {
		case OutcomeGrabbed:
			rep.Grabbed++
		case OutcomeWaiting:
			rep.Waiting++
		case OutcomeNothing:
			rep.Nothing++
		default:
			rep.Failed++
			s.logger.Warn("wanted: search failed", "want", want.Artist+" - "+want.Title, "err", out.Error)
		}
	}
	return rep
}

// wantFor describes a want for the matcher, with its editions' track counts
// from the catalogue (read from MusicBrainz the first time when it can be).
func (s *Searcher) wantFor(ctx context.Context, id pgtype.UUID, artist, title, primary string, secondary []string, date, group string) acquire.Want {
	w := acquire.Want{ID: id, Want: release.Want{
		Artist: artist, Title: title, Year: yearOf(date), PrimaryType: primary, SecondaryTypes: secondary,
	}}
	q := dbq.New(s.pool)
	span, err := q.EditionTrackSpan(ctx, group)
	if err == nil && span.MinTracks == 0 && s.cat != nil {
		if _, rerr := s.cat.Releases(ctx, group); rerr == nil {
			span, err = q.EditionTrackSpan(ctx, group)
		}
	}
	if err == nil {
		w.MinTracks, w.MaxTracks = int(span.MinTracks), int(span.MaxTracks)
	}
	return w
}

func yearOf(date string) int {
	if len(date) < 4 {
		return 0
	}
	y, _ := strconv.Atoi(date[:4])
	return y
}

// Searched is what one want's search came to.
type Searched struct {
	Outcome    string              `json:"outcome"`
	Considered int                 `json:"considered"`
	Best       string              `json:"best_release"`
	Verdict    string              `json:"best_verdict"`
	Grabbed    string              `json:"grabbed,omitempty"`
	Narrowed   []acquire.Narrowing `json:"narrowed"`
	Error      string              `json:"error,omitempty"`
}

// one searches for a want, takes the best release when auto-grab is on, and
// records what came of it on the want.
func (s *Searcher) one(ctx context.Context, svc *acquire.Service, want acquire.Want, autoGrab bool) Searched {
	found := svc.For(ctx, want)
	if found.KeepError != "" {
		s.logger.Warn("wanted: searched, but could not keep the candidates", "want", want.Title, "err", found.KeepError)
	}
	out := Searched{Considered: found.Considered, Narrowed: found.Narrowed}
	if out.Narrowed == nil {
		out.Narrowed = []acquire.Narrowing{}
	}
	if len(found.Candidates) > 0 {
		out.Best, out.Verdict = found.Candidates[0].Name, string(found.Candidates[0].Verdict)
	}
	switch {
	case found.Unconfigured:
		out.Outcome, out.Error = OutcomeError, "No indexer is set up, so there is nothing to search with."
	case found.Error != "":
		out.Outcome, out.Error = OutcomeError, found.Error
	case !found.ForAPerson():
		out.Outcome = OutcomeNothing
	case len(found.Grabbable()) == 0 || !autoGrab:
		out.Outcome = OutcomeWaiting
	default:
		out.Outcome = OutcomeWaiting
		s.grabBest(ctx, svc, want, found, &out)
	}
	s.record(ctx, want.ID, out)
	return out
}

// grabBest takes the best grabbable release, trying the next when one is
// refused for what its files hold.
func (s *Searcher) grabBest(ctx context.Context, svc *acquire.Service, want acquire.Want, found acquire.Result, out *Searched) {
	for i, c := range found.Grabbable() {
		if i == grabTries {
			return
		}
		took := svc.Grab(ctx, want, &c, found.Candidates, false, acquire.Origin{By: acquire.OriginSchedule})
		switch {
		case took.Added:
			out.Outcome, out.Grabbed, out.Best, out.Verdict = OutcomeGrabbed, c.Name, c.Name, string(acquire.Grab)
			if took.Error != "" {
				s.logger.Warn("wanted: took a release but could not record it", "want", want.Title, "err", took.Error)
			}
			s.logger.Info("wanted: took a release", "want", want.Title, "artist", want.Artist,
				"release", c.Name, "quality", c.Tier, "save_path", took.SavePath)
			return
		case took.Refused:
			continue
		case took.Unconfigured:
			out.Outcome, out.Error = OutcomeError, "No download client is set up, so nothing was taken."
			return
		case took.Contest != nil:
			return
		case took.Error != "":
			out.Outcome, out.Error = OutcomeError, took.Error
			return
		}
	}
}

func (s *Searcher) record(ctx context.Context, id pgtype.UUID, out Searched) {
	if err := dbq.New(s.pool).RecordWantSearch(ctx, dbq.RecordWantSearchParams{
		ID: id, Outcome: out.Outcome, Considered: int32(out.Considered),
		BestRelease: out.Best, BestVerdict: out.Verdict, SearchError: out.Error,
	}); err != nil && ctx.Err() == nil {
		s.logger.Warn("wanted: record search", "err", err)
	}
}

// SearchNow searches for one want at once, as the schedule would, for a
// person pressing Search: it spends the sources' pace but never waits on it.
func (s *Searcher) SearchNow(ctx context.Context, id pgtype.UUID) (Searched, error) {
	want, err := s.load(ctx, id)
	if err != nil {
		return Searched{}, err
	}
	svc, settings, err := acquire.Build(ctx, s.pool)
	if err != nil {
		return Searched{}, err
	}
	return s.one(ctx, svc, want, settings.AutoGrab), nil
}

// Take grabs the release named by key for a person, searching again first.
func (s *Searcher) Take(ctx context.Context, id pgtype.UUID, key string, force bool, by pgtype.UUID) (acquire.Taken, error) {
	want, err := s.load(ctx, id)
	if err != nil {
		return acquire.Taken{}, err
	}
	svc, _, err := acquire.Build(ctx, s.pool)
	if err != nil {
		return acquire.Taken{}, err
	}
	took := svc.Take(ctx, want, key, force, acquire.Origin{By: acquire.OriginOperator, User: by})
	if took.Added && took.Chosen != nil {
		s.record(ctx, id, Searched{
			Outcome: OutcomeGrabbed, Best: took.Chosen.Name, Verdict: string(took.Chosen.Verdict),
			Considered: 0, Grabbed: took.Chosen.Name,
		})
	}
	return took, nil
}

// load reads an open want for a search.
func (s *Searcher) load(ctx context.Context, id pgtype.UUID) (acquire.Want, error) {
	row, err := dbq.New(s.pool).GetWantForSearch(ctx, id)
	if err != nil {
		return acquire.Want{}, err
	}
	if row.FulfilledAt.Valid {
		return acquire.Want{}, ErrWantHeld
	}
	return s.wantFor(ctx, row.ID, row.ArtistName, row.Title, row.PrimaryType, row.SecondaryTypes,
		row.FirstReleaseDate, row.ReleaseGroupMbid), nil
}