diff --git a/README.md b/README.md index cf60c70..5f2c73b 100644 --- a/README.md +++ b/README.md @@ -47,6 +47,11 @@ Intro and Skip Credits buttons appear without any local analysis. - **Alternate sources fill the gaps.** Chapter names Plex already extracted, and optional local detection, cover items TheIntroDB does not have yet. They can never override TheIntroDB for a segment type it answered. +- **A large library finishes, a day at a time.** An item that has been looked up + is remembered, so it is never asked about twice. A run spends the day's + request allowance on the items it has never seen, stops when that is used up, + and the next run carries on from the same place. A library of tens of thousands + of items converges over a few days instead of re-asking forever. --- @@ -248,7 +253,7 @@ Run `plex-sync` with no arguments in a terminal and you get the interface: | --- | --- | | `1` | Status: what is in the library, what the ledger recorded, API quota | | `2` | Library: every matched item with its ids, sources and marker state | -| `3` | Plan: exactly what a run would change, before it changes anything | +| `3` | Plan: exactly what a run would change. Up/down moves, space turns an item on or off, `A`/`N` select all or none, `R` marks one for a re-scan | | `4` | Runs: history, and the undo journals from previous applies | | `5` | Settings: every setting, editable in place with the arrow keys and enter | | `?` | Help | @@ -266,6 +271,8 @@ plex-sync config check # validate configuration and reach both services plex-sync library # list items and the names Plex uses, for --show plex-sync preview --show "the last of us" # what a run would change, for one show plex-sync preview --save preview.json # ...and save it, to write later without Plex +plex-sync preview --deselect 1234 # leave a rating key out of the write +plex-sync preview --rescan tmdb:1399:1:1 # ask about one item again plex-sync apply --yes # write the markers (--dry-run to see them first) plex-sync apply --preview preview.json --yes # write a saved preview, without Plex plex-sync undo latest --yes # revert the most recent run @@ -298,6 +305,40 @@ database. If you would rather your own scheduler owned it, `sync --yes` and See [docs/scheduling.md](docs/scheduling.md) for systemd, launchd, Task Scheduler, cron and container arrangements. +### Large libraries + +TheIntroDB allows 1000 requests per UTC day with an API key, and 500 without one. +A library of tens of thousands of items cannot be scanned in a day, so the tool +is built to be left running rather than to be finished in one pass: + +- **An item is scanned once.** Every lookup is recorded, and a recorded item is + answered from the ledger afterwards without a request, however long ago it was + scanned. Expiring that record is what would make a large library never finish, + so nothing expires it. +- **A run uses the whole day's allowance.** It scans the items it has never seen + until the allowance is spent, then stops cleanly and logs how many are left. + That is not an error, and the nightly timer keeps its schedule. +- **The next run continues.** Because every scan is recorded, it picks up exactly + where the last one stopped. A 40,000-item library at 1000 requests a day + converges in about 40 days, and each run writes the markers it has data for. +- **Re-scanning is deliberate.** Nothing is asked about twice on a timer. When a + submission lands and you want fresh answers, name the items: + +```bash +# One item, by its lookup key (the same key the Library screen shows): +plex-sync sync --yes --rescan tmdb:1399:1:1 + +# Everything, at the cost of a full library of requests: +plex-sync sync --yes --rescan-all +``` + +In the interface, press `p` for a plan, move with the arrow keys, and press `R` +on the item you want re-scanned; planning again is what asks for it. `space` +turns an item off, which leaves it in the plan but out of the write. + +`plex-sync status` reports how many items have been scanned and how they split, +which is the number that says how far through the library the tool has got. + --- ## Configuration diff --git a/docs/architecture.md b/docs/architecture.md index 8f811a4..82bb486 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -71,8 +71,8 @@ expects, and the safety rules that come with editing a live database. | `internal/model` | the shared data types | nothing | | `internal/plexapi` | enumerate libraries, read ids, chapters and existing markers | Plex HTTP | | `internal/plexdb` | read and write markers, back up, undo | Plex SQLite | -| `internal/tidb` | TheIntroDB client: pacing, budget, cache, null times | TheIntroDB HTTP | -| `internal/ledger` | durable state: lookup cache, what we wrote, run history | our SQLite | +| `internal/tidb` | TheIntroDB client: pacing, budget, scan records, null times | TheIntroDB HTTP | +| `internal/ledger` | durable state: scan records, lookup cache, what we wrote, run history | our SQLite | | `internal/planner` | merge sources, map types, resolve ranges, decide the change set | nothing | | `internal/source` | markers from chapter names Plex extracted, and local detection for the rest | `plexapi` output, ffmpeg + fpcalc | | `internal/schedule` | the cron subset the process holds its own timer with | nothing | @@ -111,6 +111,37 @@ A segment type is won by the first enabled source that has it, and each written marker records which source produced it, so the status page and the plan output can always answer "where did this timing come from". +## Scanning a large library + +Two different questions get answered by two different pieces of ledger state, +and keeping them apart is what makes a library of tens of thousands of items +finish: + +- **"Do we still trust this body?"** — the lookup cache (`lookups`), with a TTL. + A 200 is cached for `theintrodb.hit_ttl_days` and a 404 for + `theintrodb.miss_ttl_days`, because a 404 becomes a 200 the moment someone + submits the timing. +- **"Have we spent a request on this item at all?"** — the scan record + (`scans`), with no expiry. A record means the item has been looked up, and a + lookup that finds one is answered from the cache without a request. + +The second is what a large library runs on. Time alone never causes a request: +`LookupForced` is the only thing that asks about a scanned item again, and that +is reached by naming an item for a re-scan (`--rescan`, `--rescan-all`, or `R` +on the Preview screen). Expiring the scan record would put the library back to +re-asking it forever and never finishing. + +When the day's allowance is spent the client refuses the next request, and +`internal/sync` treats that as a stopping point rather than an error: the run +ends, records the number of items still to scan, and the next run begins where +it left off. The nightly timer therefore makes progress every night instead of +failing every night. + +A plan also carries a `Selection`: the items turned off, and the items named for +a re-scan. It is recorded in the plan file so a plan made on a host and applied +in a container writes the same subset, and so the interface's selection is a +decision the writer honours rather than a note the writer ignores. + ## Idempotence and provenance The ledger records every marker the tool wrote. On the next run, a marker that diff --git a/docs/scheduling.md b/docs/scheduling.md index 5d70198..0b427bd 100644 --- a/docs/scheduling.md +++ b/docs/scheduling.md @@ -19,6 +19,37 @@ writes without `--yes`, and nothing writes while someone is watching something. Every run writes a line per item to the ledger and a log line to standard error, so `journalctl`, the Docker log or a file all work as a record of what happened. +## Large libraries, and the daily allowance + +TheIntroDB allows 1000 requests per UTC day with an API key and 500 without one, +so a library of tens of thousands of items is not scanned in one night. That is +expected, and the schedule is how it is meant to be worked through: + +- An item that has been looked up is recorded, and a recorded item is answered + from the ledger afterwards without a request. Nothing expires that record, so + an item is asked about once rather than once every couple of weeks. +- A run spends what is left of the day's allowance on items it has never seen, + then stops. It logs how many items are still to scan and exits **zero**: the + allowance being spent is a stopping point, not a failure, and a nightly timer + that reported an error every night would be a timer nobody reads. +- The next run continues from the same place, because every scan is recorded. + +A schedule therefore converges: a 40,000-item library at 1000 requests a day +gets through in about 40 days, writing the markers it has data for each night. +Raising `theintrodb.daily_budget` beyond the allowance does not help — the +server refuses the request either way; the budget is what stops the client +before the refusal. + +To ask about something again, name it. Nothing is re-scanned on a timer: + +```bash +plex-sync sync --yes --rescan tmdb:1399:1:1 # one item, by lookup key +plex-sync sync --yes --rescan-all # everything; a full library of requests +``` + +`plex-sync status` reports how many items have been scanned, split by whether +TheIntroDB had data, which is the progress figure for a library this size. + ## The built-in schedule ```bash @@ -201,8 +232,10 @@ task forever. 30 7 * * * PLEX_SYNC_STATE_DIR=/var/lib/plex-sync /usr/local/bin/plex-sync schedule --once --yes >>/var/log/plex-sync.log 2>&1 ``` -A run that finds nothing to do is not an error. One that fails exits non-zero -and logs why; cron will mail that to you if the machine can send mail. +A run that finds nothing to do is not an error. One that has simply used up the +day's request allowance exits zero as well — see "Large libraries" above — while +one that genuinely fails exits non-zero and logs why; cron will mail that to you +if the machine can send mail. ## Docker diff --git a/internal/api/server.go b/internal/api/server.go index ccbb1c1..fb2d8bb 100644 --- a/internal/api/server.go +++ b/internal/api/server.go @@ -303,8 +303,9 @@ func (s *Server) register() { Path: "/plan", Summary: "Compute the change set without writing anything", Description: "Asks TheIntroDB about every item, which can take minutes on a large " + - "library. Every answer is cached in the ledger, so a following apply does not " + - "pay for the requests twice.", + "library. An item that has already been scanned is answered from the ledger without " + + "a request, so a following apply does not pay for the requests twice and a large " + + "library is worked through a day at a time.", Tags: []string{"run"}, }, func(ctx context.Context, in *planInput) (*planOutput, error) { res, err := s.runner.Plan(ctx, sync.Options{ diff --git a/internal/cli/commands.go b/internal/cli/commands.go index ea03a06..2c3ff84 100644 --- a/internal/cli/commands.go +++ b/internal/cli/commands.go @@ -29,6 +29,14 @@ func addRunFlags(cmd *cobra.Command, opts *sync.Options) { flags.IntSliceVar(&opts.Sections, "section", nil, "limit to these Plex library section keys") flags.StringVar(&opts.Filter, "show", "", "only items whose title contains this text") flags.IntVar(&opts.Limit, "limit", 0, "examine at most this many items") + flags.StringSliceVar(&opts.Rescan, "rescan", nil, + "ask TheIntroDB about this item again, by lookup key (tmdb:1234:2:5); repeatable") + flags.BoolVar(&opts.RescanAll, "rescan-all", false, + "ask about every item again, even ones already scanned (costs a full library of requests)") + flags.IntSliceVar(&opts.Only, "select", nil, + "write only these Plex rating keys; repeatable") + flags.IntSliceVar(&opts.Deselected, "deselect", nil, + "leave these Plex rating keys out of the write; repeatable") flags.BoolVar(&opts.DryRun, "dry-run", false, "report what would happen without writing") flags.BoolVar(&opts.PlexStopped, "plex-stopped", false, "assert that Plex is stopped") flags.BoolVar(&opts.SkipSessionCheck, "skip-session-check", false, "skip the active session check") @@ -315,9 +323,14 @@ writes nothing and exits non-zero rather than doing something surprising.`), return encoder.Encode(res) } out := stdout(cmd) - fmt.Fprintf(out, "examined %d item(s), %d with data, %d without, %d lookup(s), %d cached\n", + fmt.Fprintf(out, "examined %d item(s), %d with data, %d without, %d already scanned, %d lookup(s), %d cached\n", res.Survey.Items, res.Survey.WithData, res.Survey.NoData, - res.Survey.Lookups, res.Survey.Cached) + res.Survey.Skipped, res.Survey.Lookups, res.Survey.Cached) + if res.Survey.Paused { + fmt.Fprintf(out, + "paused: the day's request allowance is spent; %d item(s) still to scan, "+ + "the next run continues from here\n", res.Survey.Remaining) + } if res.Applied { fmt.Fprintf(out, "wrote %d marker(s) across %d item(s), removed %d, skipped %d\n", res.Stats.Added, res.Stats.Written, res.Stats.Removed, res.Stats.Skipped) @@ -434,6 +447,8 @@ func newStatusCmd(g *globals) *cobra.Command { fmt.Fprintf(out, "ledger %s\n", stats.DatabasePath) fmt.Fprintf(out, "lookups %d (%d hits, %d misses)\n", stats.Lookups, stats.LookupHits, stats.LookupMisses) + fmt.Fprintf(out, "scanned %d item(s) (%d with data, %d without); these are never asked about again unless a re-scan is asked for\n", + stats.Scanned, stats.ScannedWithData, stats.ScannedNoData) fmt.Fprintf(out, "markers recorded %d across %d item(s)\n", stats.AppliedMarkers, stats.AppliedItems) fmt.Fprintf(out, "requests today %d of %d", @@ -468,8 +483,13 @@ func newStatusCmd(g *globals) *cobra.Command { func printPlan(cmd *cobra.Command, res *sync.Result, show int) { out := stdout(cmd) - fmt.Fprintf(out, "would change %d item(s) from %d examined: %d with data, %d without\n", - res.Survey.Planned, res.Survey.Items, res.Survey.WithData, res.Survey.NoData) + fmt.Fprintf(out, "would change %d item(s) from %d examined: %d with data, %d without, %d already scanned\n", + res.Survey.Planned, res.Survey.Items, res.Survey.WithData, res.Survey.NoData, res.Survey.Skipped) + if res.Survey.Paused { + fmt.Fprintf(out, + "paused: the day's request allowance is spent; %d item(s) still to scan, "+ + "the next run continues from here\n", res.Survey.Remaining) + } reasons := make([]string, 0, len(res.Survey.SkipReasons)) for reason := range res.Survey.SkipReasons { diff --git a/internal/cli/schedule.go b/internal/cli/schedule.go index 169daff..3738b6f 100644 --- a/internal/cli/schedule.go +++ b/internal/cli/schedule.go @@ -141,6 +141,15 @@ writes with --yes. "markers_removed", result.Stats.Removed, "applied", result.Applied, "took", time.Since(started).Round(time.Second).String()) + if result.Survey.Paused { + // Not a failure: the allowance is spent, everything the + // run did is recorded, and the next firing carries on from + // the same place. + log.Info("the run stopped early: the day's request allowance is spent", + "scanned", result.Survey.Skipped, + "remaining", result.Survey.Remaining, + "resume", "the next run continues from here") + } } if once { diff --git a/internal/config/config.go b/internal/config/config.go index c803ebb..387da9c 100644 --- a/internal/config/config.go +++ b/internal/config/config.go @@ -84,9 +84,14 @@ type TheIntroDB struct { // pacing at 25 leaves room for the request that lands while one is in flight. MaxPerWindow int `toml:"max_per_window"` WindowS float64 `toml:"window_s"` - // MissTTLDays is how long a cached "no data" answer is trusted. + // MissTTLDays is how long a cached "no data" body is trusted. It expires the + // body, not the record that the item was scanned: a 404 becomes a 200 the + // moment someone submits the timing, but asking about the item again is a + // re-scan rather than something time does on its own. MissTTLDays int `toml:"miss_ttl_days"` - // HitTTLDays is how long a cached answer is trusted before a refresh. + // HitTTLDays is how long a cached answer body is trusted. As with the miss + // TTL, this no longer decides when a request is made: an item that has been + // scanned at all is answered from the ledger whatever this says. HitTTLDays int `toml:"hit_ttl_days"` } diff --git a/internal/ledger/ledger.go b/internal/ledger/ledger.go index 7b26503..0bebcfc 100644 --- a/internal/ledger/ledger.go +++ b/internal/ledger/ledger.go @@ -47,7 +47,7 @@ const ( ) // schemaVersion is bumped when a migration adds tables. -const schemaVersion = 1 +const schemaVersion = 2 // schemaStatements build the database. Every one is idempotent, so Open works // on a fresh file and on an existing one alike. @@ -65,6 +65,24 @@ var schemaStatements = []string{ expires_at INTEGER NOT NULL )`, `CREATE INDEX IF NOT EXISTS idx_lookups_expires_at ON lookups (expires_at)`, + // scans is the record of which items have been looked up at all, and what + // the answer was. It is deliberately separate from the lookups cache and + // deliberately never expires. + // + // The cache answers "do we still trust this body"; this answers "have we + // spent a request on this item yet". On a library of tens of thousands of + // items against a daily allowance of 500 or 1000, the second question is + // the one that matters: a run must spend its requests on items it has never + // seen, and must be able to stop and pick up where it left off tomorrow. + // Expiring these rows is exactly what would make a large library never + // finish, so nothing here does. + `CREATE TABLE IF NOT EXISTS scans ( + key TEXT PRIMARY KEY, + status INTEGER NOT NULL, + kind TEXT NOT NULL DEFAULT '', + scanned_at INTEGER NOT NULL + )`, + `CREATE INDEX IF NOT EXISTS idx_scans_status ON scans (status)`, `CREATE TABLE IF NOT EXISTS applied ( rating_key INTEGER NOT NULL, marker_key TEXT NOT NULL, @@ -181,19 +199,25 @@ func (r Run) Duration() time.Duration { // Stats is the summary the status screen shows. type Stats struct { - DatabasePath string `json:"database_path"` - Lookups int `json:"lookups"` - LookupHits int `json:"lookup_hits"` - LookupMisses int `json:"lookup_misses"` - AppliedItems int `json:"applied_items"` - AppliedMarkers int `json:"applied_markers"` - RequestsTotal int `json:"requests_total"` - RequestsToday int `json:"requests_today"` - Runs int `json:"runs"` - LastRun *Run `json:"last_run,omitempty"` - SchemaVersion int `json:"schema_version"` - DatabaseBytes int64 `json:"database_bytes"` - LastRequestTime int64 `json:"last_request_at,omitempty"` + DatabasePath string `json:"database_path"` + Lookups int `json:"lookups"` + LookupHits int `json:"lookup_hits"` + LookupMisses int `json:"lookup_misses"` + AppliedItems int `json:"applied_items"` + AppliedMarkers int `json:"applied_markers"` + // Scanned is how many items have been looked up at all, and how those + // answers split. It is what says how far through a large library the tool + // has got, and it does not go down when the cache expires. + Scanned int `json:"scanned"` + ScannedWithData int `json:"scanned_with_data"` + ScannedNoData int `json:"scanned_no_data"` + RequestsTotal int `json:"requests_total"` + RequestsToday int `json:"requests_today"` + Runs int `json:"runs"` + LastRun *Run `json:"last_run,omitempty"` + SchemaVersion int `json:"schema_version"` + DatabaseBytes int64 `json:"database_bytes"` + LastRequestTime int64 `json:"last_request_at,omitempty"` } // Open opens, creating if needed, the ledger at path. @@ -275,13 +299,24 @@ func (l *Ledger) migrate() error { if err := l.db.QueryRow(`SELECT COUNT(*) FROM schema_version`).Scan(&have); err != nil { return fmt.Errorf("ledger: read schema version: %w", err) } - if have == 0 { + switch { + case have == 0: if _, err := l.db.Exec( `INSERT INTO schema_version (version, applied_at) VALUES (?, ?)`, schemaVersion, l.now().Unix(), ); err != nil { return fmt.Errorf("ledger: record schema version: %w", err) } + default: + // Every statement above is idempotent, so an existing file gains the + // tables it is missing just by being opened. The recorded version is + // what says which build wrote it last, so it is advanced to match. + if _, err := l.db.Exec( + `UPDATE schema_version SET version = ?, applied_at = ?`, + schemaVersion, l.now().Unix(), + ); err != nil { + return fmt.Errorf("ledger: record schema version: %w", err) + } } return nil } @@ -416,6 +451,107 @@ func (l *Ledger) PurgeExpired(now time.Time) (int, error) { return int(n), nil } +// --------------------------------------------------------------------------- +// Scan records +// --------------------------------------------------------------------------- + +// ScannedItem is the record that an item has been looked up, and what the +// answer was. +// +// It is what makes a large library finish. The lookup cache tells the client +// whether a stored body is still trustworthy; this tells it whether the item +// needs a request at all, and it never expires. A run spends its daily +// allowance on items with no record here and leaves the rest for tomorrow. +type ScannedItem struct { + // Key is the lookup key (provider:id[:season:episode]). + Key string + // Status is the status the item was scanned with: 200 or 404. + Status int + // Kind is the library kind: movie or episode. + Kind string + // ScannedAt is when the item was last scanned. + ScannedAt time.Time +} + +// RecordScan remembers that an item has been looked up, and what came back. +// +// It is written with every conclusive answer (200 or 404), and it is never +// expired: a re-scan happens when a caller asks for one, not because time +// passed. It is idempotent, so a forced re-scan simply refreshes it. +func (l *Ledger) RecordScan(key string, status int, kind string) error { + if strings.TrimSpace(key) == "" { + return errors.New("ledger: empty scan key") + } + l.mu.Lock() + defer l.mu.Unlock() + _, err := l.db.Exec( + `INSERT INTO scans (key, status, kind, scanned_at) + VALUES (?, ?, ?, ?) + ON CONFLICT(key) DO UPDATE SET + status = excluded.status, + kind = excluded.kind, + scanned_at = excluded.scanned_at`, + key, status, kind, l.now().Unix(), + ) + if err != nil { + return fmt.Errorf("ledger: record scan %s: %w", key, err) + } + return nil +} + +// Scan returns the scan record for key. The bool reports whether the item has +// been scanned at all. +func (l *Ledger) Scan(key string) (ScannedItem, bool) { + if strings.TrimSpace(key) == "" { + return ScannedItem{}, false + } + var ( + out ScannedItem + scannedAt int64 + ) + err := l.db.QueryRow( + `SELECT key, status, kind, scanned_at FROM scans WHERE key = ?`, + key, + ).Scan(&out.Key, &out.Status, &out.Kind, &scannedAt) + if err != nil { + return ScannedItem{}, false + } + out.ScannedAt = time.Unix(scannedAt, 0) + return out, true +} + +// Scanned reports whether an item has been scanned. +func (l *Ledger) Scanned(key string) bool { + _, found := l.Scan(key) + return found +} + +// ForgetScan drops an item's scan record, so the next run looks it up again. +// It is what an explicit re-scan of one item leaves behind. +func (l *Ledger) ForgetScan(key string) error { + l.mu.Lock() + defer l.mu.Unlock() + if _, err := l.db.Exec(`DELETE FROM scans WHERE key = ?`, key); err != nil { + return fmt.Errorf("ledger: forget scan %s: %w", key, err) + } + return nil +} + +// ScanCounts reports how many items have been scanned, split by what the answer +// was. It is the progress figure a large library is judged by. +func (l *Ledger) ScanCounts() (total, withData, noData int, err error) { + if err := l.db.QueryRow(`SELECT COUNT(*) FROM scans`).Scan(&total); err != nil { + return 0, 0, 0, fmt.Errorf("ledger: count scans: %w", err) + } + if err := l.db.QueryRow(`SELECT COUNT(*) FROM scans WHERE status = 200`).Scan(&withData); err != nil { + return 0, 0, 0, fmt.Errorf("ledger: count scans with data: %w", err) + } + if err := l.db.QueryRow(`SELECT COUNT(*) FROM scans WHERE status = 404`).Scan(&noData); err != nil { + return 0, 0, 0, fmt.Errorf("ledger: count scans without data: %w", err) + } + return total, withData, noData, nil +} + // --------------------------------------------------------------------------- // Markers we wrote // --------------------------------------------------------------------------- @@ -675,6 +811,11 @@ func (l *Ledger) Stats() (Stats, error) { if err := count(`SELECT COUNT(*) FROM runs`, &out.Runs); err != nil { return out, err } + total, withData, noData, err := l.ScanCounts() + if err != nil { + return out, err + } + out.Scanned, out.ScannedWithData, out.ScannedNoData = total, withData, noData today, err := l.RequestsToday(SourceAny) if err != nil { return out, err diff --git a/internal/ledger/ledger_test.go b/internal/ledger/ledger_test.go index ea8a381..5b68148 100644 --- a/internal/ledger/ledger_test.go +++ b/internal/ledger/ledger_test.go @@ -43,7 +43,7 @@ func TestOpenCreatesSchema(t *testing.T) { if err := rows.Err(); err != nil { t.Fatalf("read schema: %v", err) } - for _, want := range []string{"applied", "lookups", "requests", "runs", "schema_version"} { + for _, want := range []string{"applied", "lookups", "requests", "runs", "schema_version", "scans"} { if !got[want] { t.Errorf("table %q missing, have %v", want, got) } @@ -205,6 +205,116 @@ func TestForgetLookupAndPurgeExpired(t *testing.T) { } } +func TestOpeningAnOlderLedgerAddsTheScanTable(t *testing.T) { + path := filepath.Join(t.TempDir(), "ledger.db") + + l, err := Open(path) + if err != nil { + t.Fatalf("Open: %v", err) + } + // Make the file look like one written before the scan records existed. + if _, err := l.db.Exec(`DROP TABLE scans`); err != nil { + t.Fatalf("drop scans: %v", err) + } + if _, err := l.db.Exec(`UPDATE schema_version SET version = 1`); err != nil { + t.Fatalf("age the schema version: %v", err) + } + if err := l.Close(); err != nil { + t.Fatalf("Close: %v", err) + } + + // Opening it again is the migration: nothing else has to be run. + upgraded, err := Open(path) + if err != nil { + t.Fatalf("reopen: %v", err) + } + t.Cleanup(func() { _ = upgraded.Close() }) + + if err := upgraded.RecordScan("tmdb:1:movie", 200, "movie"); err != nil { + t.Fatalf("RecordScan on an upgraded ledger: %v", err) + } + if !upgraded.Scanned("tmdb:1:movie") { + t.Error("the scan record did not survive being written") + } + var version int + if err := upgraded.db.QueryRow(`SELECT version FROM schema_version`).Scan(&version); err != nil { + t.Fatalf("read schema version: %v", err) + } + if version != schemaVersion { + t.Errorf("schema version after opening an older file = %d, want %d", version, schemaVersion) + } +} + +func TestScanRecordsLifecycle(t *testing.T) { + l := openTest(t) + + if l.Scanned("tmdb:1:movie") { + t.Error("an item was reported as scanned before it was") + } + if _, found := l.Scan("tmdb:1:movie"); found { + t.Error("Scan found a record that was never written") + } + + if err := l.RecordScan("tmdb:1:movie", 200, "movie"); err != nil { + t.Fatalf("RecordScan: %v", err) + } + if err := l.RecordScan("tmdb:2:1:4", 404, "episode"); err != nil { + t.Fatalf("RecordScan: %v", err) + } + if err := l.RecordScan("", 200, "movie"); err == nil { + t.Error("RecordScan with an empty key should fail") + } + + got, found := l.Scan("tmdb:1:movie") + if !found { + t.Fatal("the scan record was not stored") + } + if got.Status != 200 || got.Kind != "movie" || !got.ScannedAt.Equal(fakeNow) { + t.Errorf("scan record = %+v, want status 200, kind movie, stamped now", got) + } + + total, withData, noData, err := l.ScanCounts() + if err != nil { + t.Fatalf("ScanCounts: %v", err) + } + if total != 2 || withData != 1 || noData != 1 { + t.Errorf("ScanCounts = %d/%d/%d, want 2 total, 1 with data, 1 without", total, withData, noData) + } + + stats, err := l.Stats() + if err != nil { + t.Fatalf("Stats: %v", err) + } + if stats.Scanned != 2 || stats.ScannedWithData != 1 || stats.ScannedNoData != 1 { + t.Errorf("Stats scanned = %d/%d/%d, want 2/1/1", + stats.Scanned, stats.ScannedWithData, stats.ScannedNoData) + } + + // Recording again refreshes what is known about the item rather than + // adding a second row: a re-scan that finds data replaces the no-data. + if err := l.RecordScan("tmdb:2:1:4", 200, "episode"); err != nil { + t.Fatalf("RecordScan: %v", err) + } + if got, _ := l.Scan("tmdb:2:1:4"); got.Status != 200 { + t.Errorf("status after re-scanning = %d, want 200", got.Status) + } + if total, _, _, _ := l.ScanCounts(); total != 2 { + t.Errorf("total after a re-scan = %d, want 2: re-scanning must not duplicate a row", total) + } + + // Forgetting one is what asking for a single item to be looked up again + // leaves behind. + if err := l.ForgetScan("tmdb:1:movie"); err != nil { + t.Fatalf("ForgetScan: %v", err) + } + if l.Scanned("tmdb:1:movie") { + t.Error("ForgetScan left the record behind") + } + if total, _, _, _ := l.ScanCounts(); total != 1 { + t.Errorf("total after forgetting = %d, want 1", total) + } +} + func TestAppliedMarkersLifecycle(t *testing.T) { l := openTest(t) diff --git a/internal/model/model.go b/internal/model/model.go index 102ea4a..fb7a2e8 100644 --- a/internal/model/model.go +++ b/internal/model/model.go @@ -347,6 +347,9 @@ type Plan struct { Sources map[string]int `json:"sources"` // Options echoes the planner settings the plan was built with. Options PlanOptions `json:"options"` + // Selection records what was chosen about this plan: the items turned off, + // and the items to re-scan. Absent means everything, nothing re-scanned. + Selection *Selection `json:"selection,omitempty"` } // PlanOptions records the knobs a plan was produced with, so an old plan file @@ -361,6 +364,91 @@ type PlanOptions struct { Sources []string `json:"sources"` } +// Selection records what was chosen about a plan, as opposed to what the plan +// found. +// +// A plan is a snapshot of a library; this is the decision taken on top of it. +// It is stored with the plan so that a plan saved on a host and applied in a +// container keeps the same answers, and so a large library can be worked through +// a piece at a time. +// +// The empty value means "everything, and nothing re-scanned", which is what a +// scheduled run wants when nobody has said otherwise. Both lists are therefore +// exceptions rather than selections. +type Selection struct { + // Unselected lists the rating keys to leave out of the write. An item that + // is off stays in the plan and stays visible on the preview screen; it is + // simply not applied. + Unselected []int `json:"unselected,omitempty"` + // Rescan lists lookup keys to ask TheIntroDB about again, whatever the + // record of earlier scans says. It is how an item that was scanned long ago + // gets a fresh answer: nothing expires on its own, so the only re-scan is + // the one asked for here. + Rescan []string `json:"rescan,omitempty"` +} + +// Selected reports whether an item is part of what the plan should write. +func (s *Selection) Selected(ratingKey int) bool { + if s == nil { + return true + } + for _, key := range s.Unselected { + if key == ratingKey { + return false + } + } + return true +} + +// RescanKeys returns the lookup keys marked for a re-scan, as a set. +func (s *Selection) RescanKeys() map[string]bool { + out := map[string]bool{} + if s == nil { + return out + } + for _, key := range s.Rescan { + out[key] = true + } + return out +} + +// Select turns an item on or off. The list of exceptions is kept sorted and +// free of duplicates, so two plans made the same way compare equal. +func (s *Selection) Select(ratingKey int, selected bool) { + if s == nil { + return + } + kept := s.Unselected[:0] + for _, key := range s.Unselected { + if key != ratingKey { + kept = append(kept, key) + } + } + s.Unselected = kept + if !selected { + s.Unselected = append(s.Unselected, ratingKey) + sort.Ints(s.Unselected) + } +} + +// MarkRescan adds or removes one lookup key from the re-scan list. +func (s *Selection) MarkRescan(key string, rescan bool) { + if s == nil || strings.TrimSpace(key) == "" { + return + } + kept := s.Rescan[:0] + for _, existing := range s.Rescan { + if existing != key { + kept = append(kept, existing) + } + } + s.Rescan = kept + if rescan { + s.Rescan = append(s.Rescan, key) + sort.Strings(s.Rescan) + } +} + // Work returns the items that need a change. func (p Plan) Work() []ItemPlan { var out []ItemPlan @@ -372,6 +460,30 @@ func (p Plan) Work() []ItemPlan { return out } +// SelectedWork returns the items that need a change and are still selected. +// +// This is what a write acts on: the plan says what could change, the selection +// says what was agreed to. With no selection recorded it is the same as Work. +func (p Plan) SelectedWork() []ItemPlan { + var out []ItemPlan + for _, it := range p.Work() { + if p.Selection.Selected(it.Item.RatingKey) { + out = append(out, it) + } + } + return out +} + +// EnsureSelection returns the plan's selection, creating an empty one when the +// plan has none, so a caller can record a choice on a plan that had no +// exceptions yet. +func (p *Plan) EnsureSelection() *Selection { + if p.Selection == nil { + p.Selection = &Selection{} + } + return p.Selection +} + // SortByLabel orders items by their display label, for stable output. func SortByLabel(items []LibraryItem) { sort.Slice(items, func(i, j int) bool { return items[i].Label() < items[j].Label() }) diff --git a/internal/model/model_test.go b/internal/model/model_test.go new file mode 100644 index 0000000..7e8ce87 --- /dev/null +++ b/internal/model/model_test.go @@ -0,0 +1,111 @@ +package model + +import "testing" + +// changeable builds an item that needs a write, so that Work and SelectedWork +// have something to act on. +func changeable(ratingKey int) ItemPlan { + return ItemPlan{ + Item: LibraryItem{RatingKey: ratingKey, Title: "item"}, + Add: []Marker{{ + Text: MarkerIntro, StartMS: 0, EndMS: 1000, Source: string(SourceTheIntroDB), + }}, + Reason: "add", + } +} + +func TestAnAbsentSelectionKeepsEverything(t *testing.T) { + plan := Plan{Items: []ItemPlan{changeable(1), changeable(2)}} + + if len(plan.SelectedWork()) != 2 { + t.Errorf("SelectedWork with no selection = %d, want 2: absent means everything", + len(plan.SelectedWork())) + } + // A nil selection must answer safely, because a plan read from an older + // file has none. + var none *Selection + if !none.Selected(7) { + t.Error("a nil selection reported an item as unselected") + } + if len(none.RescanKeys()) != 0 { + t.Error("a nil selection reported re-scan keys") + } +} + +func TestSelectingAndDeselecting(t *testing.T) { + selection := &Selection{} + + selection.Select(2, false) + if selection.Selected(2) { + t.Error("item 2 was deselected but still reads as selected") + } + if !selection.Selected(3) { + t.Error("deselecting item 2 turned off item 3") + } + + // Deselecting twice must not record the key twice: a plan made the same way + // twice should be identical. + selection.Select(2, false) + if len(selection.Unselected) != 1 { + t.Errorf("unselected = %v, want one entry", selection.Unselected) + } + + selection.Select(2, true) + if !selection.Selected(2) || len(selection.Unselected) != 0 { + t.Errorf("re-selecting left %v behind", selection.Unselected) + } +} + +func TestMarkingForRescan(t *testing.T) { + selection := &Selection{} + + selection.MarkRescan("tmdb:1:movie", true) + selection.MarkRescan("tmdb:2:1:4", true) + if keys := selection.RescanKeys(); !keys["tmdb:1:movie"] || !keys["tmdb:2:1:4"] { + t.Errorf("RescanKeys = %v, want both marked keys", keys) + } + + // Marking twice is not two entries, and unmarking is exact. + selection.MarkRescan("tmdb:1:movie", true) + if len(selection.Rescan) != 2 { + t.Errorf("rescan list = %v, want two entries", selection.Rescan) + } + selection.MarkRescan("tmdb:1:movie", false) + if keys := selection.RescanKeys(); keys["tmdb:1:movie"] { + t.Errorf("RescanKeys = %v, want the unmarked key gone", keys) + } + + // A blank key is not a lookup that can happen, so it is not recorded. + selection.MarkRescan(" ", true) + if len(selection.Rescan) != 1 { + t.Errorf("rescan list = %v, want the blank key ignored", selection.Rescan) + } +} + +func TestSelectedWorkLeavesItemsOut(t *testing.T) { + plan := Plan{Items: []ItemPlan{changeable(1), changeable(2), changeable(3)}} + plan.EnsureSelection().Select(2, false) + + work := plan.SelectedWork() + if len(work) != 2 { + t.Fatalf("SelectedWork = %d items, want 2", len(work)) + } + for _, item := range work { + if item.Item.RatingKey == 2 { + t.Error("a deselected item is still in the work") + } + } + if len(plan.Work()) != 3 { + t.Errorf("Work = %d, want 3: deselecting must not hide items from the preview", + len(plan.Work())) + } +} + +func TestEnsureSelectionIsStable(t *testing.T) { + plan := Plan{} + first := plan.EnsureSelection() + second := plan.EnsureSelection() + if first != second { + t.Error("EnsureSelection replaced an existing selection") + } +} diff --git a/internal/planfile/planfile.go b/internal/planfile/planfile.go index 64f99ee..c3bc95c 100644 --- a/internal/planfile/planfile.go +++ b/internal/planfile/planfile.go @@ -64,7 +64,7 @@ func Save(path string, plan *model.Plan, meta Meta) error { if meta.CreatedAt.IsZero() { meta.CreatedAt = time.Now() } - meta.Items = len(plan.Work()) + meta.Items = len(plan.SelectedWork()) body, err := json.MarshalIndent(File{Format: Format, Meta: meta, Plan: *plan}, "", " ") if err != nil { diff --git a/internal/sync/sync.go b/internal/sync/sync.go index 03a45d2..8b1e59d 100644 --- a/internal/sync/sync.go +++ b/internal/sync/sync.go @@ -55,6 +55,21 @@ type Options struct { ForceCreateInitialTag bool // Sources overrides the enabled alternate sources for this run. Sources []string + // Rescan lists lookup keys to ask TheIntroDB about again although they have + // already been scanned. It is the only way an item that was scanned before + // gets a second request: nothing expires on its own, so the answer for a + // large library is stable until someone asks for it to change. + Rescan []string + // RescanAll asks about every item again, scanned or not. It is a full + // refresh, and it costs a full library of requests. + RescanAll bool + // Only, when non-empty, limits the write to these rating keys. It narrows the + // plan's own selection rather than replacing it, so it cannot bring back an + // item the plan turned off. + Only []int + // Deselected lists rating keys to leave out of the write. It is what the + // preview screen's selection becomes. + Deselected []int // Progress receives stage and item updates. It may be nil. Progress func(Event) @@ -87,6 +102,23 @@ type Survey struct { BudgetKnown bool Errors []string ChapterItems int + // Skipped counts the items answered from the record of an earlier scan, + // with no request. On a large library this is most of a run, and it is the + // number that says the library is being covered rather than re-covered. + Skipped int + // Rescanned counts the items asked about again because they were named for + // a re-scan. + Rescanned int + // Remaining is how many items still had no scan record when the run + // stopped, counted from the items this run examined. + Remaining int + // Paused reports that the run stopped early because the day's request + // allowance was spent. It is not a failure: the next run picks up from + // here, which is how a library of tens of thousands of items is worked + // through a day at a time. + Paused bool + // PauseReason explains why the run paused, for the log and the screens. + PauseReason string } // Result is the outcome of a plan or a run. @@ -268,6 +300,8 @@ func (r *Runner) Plan(ctx context.Context, opts Options) (*Result, error) { existing := map[int][]model.ExistingMarker{} written := map[int][]model.Marker{} sets := map[int]map[model.SourceName]model.SegmentSet{} + rescans := rescanSet(opts.Rescan) + paused := false for index, item := range items { if err := ctx.Err(); err != nil { return res, err @@ -289,22 +323,55 @@ func (r *Runner) Plan(ctx context.Context, opts Options) (*Result, error) { itemSets := map[model.SourceName]model.SegmentSet{} - // TheIntroDB first. Its answer is cached in the ledger, so repeat runs - // cost nothing until the cache entry expires. - if _, ok := item.LookupKey(); ok { - body, look, err := r.app.TIDB.Lookup(ctx, item) + // TheIntroDB first. An item that has already been scanned is answered + // from what the ledger holds from then, without a request, so a run + // spends its allowance on the items it has never seen. Naming an item + // for a re-scan is the only thing that asks about it twice. + if key, ok := item.LookupKey(); ok { + force := opts.RescanAll || rescans[key] + var ( + body model.SegmentSet + look tidb.LookupResult + ) + if force { + body, look, err = r.app.TIDB.LookupForced(ctx, item) + } else { + body, look, err = r.app.TIDB.Lookup(ctx, item) + } res.Survey.Lookups++ - if err != nil { + switch { + case err != nil && tidb.IsBudgetError(err): + // The day's request allowance is spent. This is not a + // failure: the scan stops here, everything it did is already + // recorded, and the next run carries on from the same place. + // That is what lets a library of tens of thousands of items + // finish, a few hundred or a thousand items at a time. + res.Survey.Paused = true + res.Survey.PauseReason = err.Error() + r.app.Log.Warn("stopping the scan: the request allowance is spent", + "examined", index+1, "of", len(items), + "resume", "the next run continues from here, because every scan is recorded") + paused = true + + case err != nil: if tidb.IsTerminal(err) { // A rejected key or an item with no usable id: retrying in // this run cannot help, so stop rather than hammering it. return res, fmt.Errorf("%s: %w", item.Label(), err) } res.Survey.Errors = append(res.Survey.Errors, item.Label()+": "+err.Error()) - } else { + + default: if look.Cached { res.Survey.Cached++ } + if look.Skipped { + res.Survey.Skipped++ + } else if force { + // A re-scan that reached the network rather than the + // record of a previous one. + res.Survey.Rescanned++ + } res.Survey.BudgetLeft = look.Remaining res.Survey.BudgetKnown = look.RemainingKnown if look.Status == 200 && len(body.Segments) > 0 { @@ -315,6 +382,9 @@ func (r *Runner) Plan(ctx context.Context, opts Options) (*Result, error) { } } } + if paused { + break + } // Chapters, when enabled. Free and exact for this file, so it also // covers the item when TheIntroDB had nothing. @@ -349,7 +419,23 @@ func (r *Runner) Plan(ctx context.Context, opts Options) (*Result, error) { PALSpedUp: planner.PALSpedUp(seen), } res.Plan = planner.Build(seen, inputs, *cfg) - res.Survey.Planned = len(res.Plan.Work()) + + // Record what was asked for, so a plan saved from this run says which items + // were named for a re-scan, and so an apply can be told what was chosen. + if len(opts.Rescan) > 0 || opts.RescanAll { + selection := res.Plan.EnsureSelection() + for _, key := range opts.Rescan { + selection.MarkRescan(key, true) + } + } + if paused { + res.Survey.Remaining = r.countRemaining(seen) + // Report what was examined rather than the size of the library: a run + // that stopped early has not looked at the rest, and saying it did + // would make the summary disagree with the plan underneath it. + res.Survey.Items = len(seen) + } + res.Survey.Planned = len(res.Plan.SelectedWork()) for _, item := range res.Plan.Items { if item.Skipped() { res.Survey.SkipReasons[item.Reason]++ @@ -369,7 +455,7 @@ func (r *Runner) Apply(ctx context.Context, res *Result, opts Options) error { if res == nil { return errors.New("nothing to apply") } - work := res.Plan.Work() + work := selectedWork(res.Plan, opts) if len(work) == 0 { r.app.Log.Info("nothing to do") return nil @@ -523,7 +609,7 @@ func (r *Runner) ApplyPlanFile(ctx context.Context, path string, opts Options) ( } r.app.Log.Info("applying a saved plan", "path", path, - "items", len(plan.Work()), + "items", len(plan.SelectedWork()), "made", meta.Describe()) res := &Result{Plan: *plan} @@ -659,6 +745,13 @@ func (r *Runner) recordRun(started time.Time, kind string, res *Result, runErr e if runErr != nil { run.Status = "error" run.Note = kind + ": " + runErr.Error() + } else if res != nil && res.Survey.Paused { + // A run that stopped because the day's allowance was spent did what it + // set out to do and simply ran out of requests. Recording it as an + // error would be wrong, and a nightly timer that reports failure every + // night is a timer nobody reads. + run.Status = "paused" + run.Note = kind + " (paused: allowance spent)" } if res != nil { run.Items = res.Survey.Items @@ -686,6 +779,65 @@ func (r *Runner) emit(opts Options, event Event) { } } +// countRemaining reports how many of the items a run examined still have no +// scan record, which is the work it is leaving for the next run. +func (r *Runner) countRemaining(items []model.LibraryItem) int { + if r.app.Ledger == nil { + return 0 + } + left := 0 + for _, item := range items { + key, ok := item.LookupKey() + if !ok { + continue + } + if !r.app.Ledger.Scanned(key) { + left++ + } + } + return left +} + +// rescanSet turns a list of lookup keys into a set, ignoring blanks. +func rescanSet(keys []string) map[string]bool { + out := make(map[string]bool, len(keys)) + for _, key := range keys { + if trimmed := strings.TrimSpace(key); trimmed != "" { + out[trimmed] = true + } + } + return out +} + +// selectedWork is the part of a plan a run should write: the items that need a +// change, minus the ones turned off in the plan, minus the ones the caller +// excluded, and restricted to the caller's whitelist when it gave one. +// +// Without this, a preview screen's selection would be decoration: the plan +// would be written in full whatever was chosen. +func selectedWork(plan model.Plan, opts Options) []model.ItemPlan { + only := make(map[int]bool, len(opts.Only)) + for _, key := range opts.Only { + only[key] = true + } + off := make(map[int]bool, len(opts.Deselected)) + for _, key := range opts.Deselected { + off[key] = true + } + + var out []model.ItemPlan + for _, item := range plan.SelectedWork() { + if len(only) > 0 && !only[item.Item.RatingKey] { + continue + } + if off[item.Item.RatingKey] { + continue + } + out = append(out, item) + } + return out +} + // filterItems applies the run's section, filter and limit options. func filterItems(items []model.LibraryItem, opts Options) []model.LibraryItem { out := make([]model.LibraryItem, 0, len(items)) diff --git a/internal/sync/sync_test.go b/internal/sync/sync_test.go new file mode 100644 index 0000000..0ee8312 --- /dev/null +++ b/internal/sync/sync_test.go @@ -0,0 +1,80 @@ +package sync + +import ( + "testing" + + "github.com/TheIntroDB/plex-sync/internal/model" +) + +// changeable builds an item that needs a write. +func changeable(ratingKey int) model.ItemPlan { + return model.ItemPlan{ + Item: model.LibraryItem{RatingKey: ratingKey, Title: "item"}, + Add: []model.Marker{{ + Text: model.MarkerIntro, StartMS: 0, EndMS: 1000, Source: string(model.SourceTheIntroDB), + }}, + Reason: "add", + } +} + +func keys(items []model.ItemPlan) []int { + var out []int + for _, item := range items { + out = append(out, item.Item.RatingKey) + } + return out +} + +// A preview screen's selection has to reach the writer, or it is decoration. +func TestSelectedWorkAppliesThePlansOwnSelection(t *testing.T) { + plan := model.Plan{Items: []model.ItemPlan{changeable(1), changeable(2), changeable(3)}} + plan.EnsureSelection().Select(2, false) + + work := selectedWork(plan, Options{}) + if len(work) != 2 { + t.Fatalf("selectedWork = %v, want items 1 and 3", keys(work)) + } + if len(work) == 2 && (work[0].Item.RatingKey == 2 || work[1].Item.RatingKey == 2) { + t.Errorf("selectedWork = %v, want item 2 left out", keys(work)) + } +} + +func TestSelectedWorkHonoursTheCallersFlags(t *testing.T) { + plan := model.Plan{Items: []model.ItemPlan{changeable(1), changeable(2), changeable(3)}} + + // --deselect removes an item without touching the plan. + work := selectedWork(plan, Options{Deselected: []int{1}}) + if len(work) != 2 { + t.Errorf("selectedWork = %v, want items 2 and 3", keys(work)) + } + + // --select narrows the write to exactly these keys. + work = selectedWork(plan, Options{Only: []int{2}}) + if len(work) != 1 || work[0].Item.RatingKey != 2 { + t.Errorf("selectedWork = %v, want only item 2", keys(work)) + } + + // It narrows rather than replaces: a plan that turned an item off keeps it + // off, so a flag cannot silently reintroduce something the plan excluded. + plan.EnsureSelection().Select(1, true) + plan.EnsureSelection().Select(2, false) + if got := selectedWork(plan, Options{Only: []int{1, 2}}); len(got) != 1 || got[0].Item.RatingKey != 1 { + t.Errorf("selectedWork = %v, want only the still-selected item 1", keys(got)) + } + + // An empty plan stays empty rather than becoming an accident. + if got := selectedWork(model.Plan{}, Options{}); len(got) != 0 { + t.Errorf("selectedWork on an empty plan = %v, want nothing", keys(got)) + } +} + +func TestRescanSetIgnoresBlanks(t *testing.T) { + set := rescanSet([]string{"tmdb:1:movie", " ", "tmdb:2:1:4"}) + if len(set) != 2 || !set["tmdb:1:movie"] || !set["tmdb:2:1:4"] { + t.Errorf("rescanSet = %v, want the two real keys", set) + } + // A key's own whitespace is trimmed rather than kept as part of the key. + if !rescanSet([]string{" tmdb:1:movie "})["tmdb:1:movie"] { + t.Error("rescanSet did not trim a key") + } +} diff --git a/internal/tidb/client.go b/internal/tidb/client.go index 859c7e6..d15a16b 100644 --- a/internal/tidb/client.go +++ b/internal/tidb/client.go @@ -1,5 +1,5 @@ -// Package tidb is the TheIntroDB API client: lookups, the response cache, the -// request pacing and the daily budget. +// Package tidb is the TheIntroDB API client: lookups, the scan record, the +// response cache, the request pacing and the daily budget. // // It goes through internal/httpclient (Fiber's client) for every outbound call, // and through internal/ledger for every piece of durable state, so this package @@ -81,6 +81,10 @@ const ( ReasonMiss = "miss" // ReasonNoData: TheIntroDB has nothing for this item (HTTP 404). ReasonNoData = "no-data" + // ReasonScanned: the item had already been scanned, so the stored answer + // was used and no request was made. It is what a run over a large library + // spends most of its time reporting: the items it has already covered. + ReasonScanned = "scanned" // ReasonBudget: the daily request budget is spent, so no request was made. ReasonBudget = "budget" // ReasonRateLimit: the server rate-limited the request (HTTP 429). @@ -135,6 +139,20 @@ func IsTerminal(err error) bool { return errors.As(err, &e) && e.IsTerminal() } +// IsBudgetError reports whether err is the day's allowance refusing a request, +// either because the ledger's own count reached the budget or because the +// server said the allowance was spent. +// +// A scan treats it as a stopping point rather than a failure: the allowance is +// spent, the item was not looked up, and the next run continues from here. +func IsBudgetError(err error) bool { + var e *Error + if !errors.As(err, &e) { + return false + } + return e.Kind == KindBudget || e.Kind == KindUsageLimit +} + // Usage is the request accounting the status screen shows. type Usage struct { // Requests is every API request this process made. @@ -143,6 +161,10 @@ type Usage struct { Lookups int `json:"lookups"` // CacheHits is the lookups answered from the ledger with no network call. CacheHits int `json:"cache_hits"` + // Skipped is the lookups answered because the item had already been + // scanned at some point. It is the part of CacheHits that a large library + // is made of: the items a run does not have to ask about again. + Skipped int `json:"skipped"` // Data is the lookups TheIntroDB answered with segments. Data int `json:"data"` // NoData is the lookups TheIntroDB answered 404. @@ -189,6 +211,7 @@ type Client struct { requests int lookups int cacheHits int + skipped int data int noData int rateLimited int @@ -475,6 +498,7 @@ func (c *Client) Usage() Usage { Requests: c.requests, Lookups: c.lookups, CacheHits: c.cacheHits, + Skipped: c.skipped, Data: c.data, NoData: c.noData, RateLimited: c.rateLimited, diff --git a/internal/tidb/client_test.go b/internal/tidb/client_test.go index 2414692..3d36e4c 100644 --- a/internal/tidb/client_test.go +++ b/internal/tidb/client_test.go @@ -371,31 +371,36 @@ func TestLookupFreshThenCached(t *testing.T) { t.Errorf("cached = %+v, want the raw 200 body and kind movie", cached) } - // The second lookup is answered from the ledger, with no network call. + // The second lookup is answered from the ledger, with no network call: the + // item has been scanned, so it is not asked about again. set2, res2, err := h.client.Lookup(context.Background(), item) if err != nil { t.Fatalf("second Lookup: %v", err) } - if !res2.Cached || res2.Reason != ReasonHit || res2.Status != 200 { - t.Errorf("second result = %+v, want a cached hit", res2) + if !res2.Cached || !res2.Skipped || res2.Reason != ReasonScanned || res2.Status != 200 { + t.Errorf("second result = %+v, want a scanned answer with no request", res2) } if len(set2.Segments) != len(set.Segments) { t.Errorf("cached segments = %+v, want the same as the first answer", set2.Segments) } if h.server.Count() != 1 { - t.Errorf("server saw %d requests, want 1: a fresh entry must not be re-fetched", h.server.Count()) + t.Errorf("server saw %d requests, want 1: a scanned item must not be re-fetched", h.server.Count()) } usage := h.client.Usage() - if usage.Requests != 1 || usage.Lookups != 2 || usage.CacheHits != 1 || usage.Data != 2 { - t.Errorf("Usage = %+v, want 1 request, 2 lookups, 1 cache hit, 2 data", usage) + if usage.Requests != 1 || usage.Lookups != 2 || usage.CacheHits != 1 || usage.Skipped != 1 || usage.Data != 2 { + t.Errorf("Usage = %+v, want 1 request, 2 lookups, 1 cache hit, 1 skipped, 2 data", usage) } if usage.Today != 1 { t.Errorf("Usage.Today = %d, want 1", usage.Today) } } -func TestLookup404IsCachedButExpires(t *testing.T) { +// A 404 is remembered. It is cached for MissTTLDays so the body expires, but the +// record that the item was scanned does not: a library of tens of thousands of +// items against a few hundred requests a day only ever finishes if an item is +// asked about once. Asking again is a re-scan, and nothing does that on a timer. +func TestScannedItemIsNotAskedAgainWhenTheCacheExpires(t *testing.T) { h := newHarness(t, func(call int, w http.ResponseWriter, r *http.Request) { js(w, 404, `{"error":"no data"}`) }, func(cfg *config.TheIntroDB) { cfg.MissTTLDays = 14 }) @@ -418,31 +423,54 @@ func TestLookup404IsCachedButExpires(t *testing.T) { if h.server.Count() != 1 { t.Fatalf("server saw %d requests, want 1", h.server.Count()) } + if !h.ledger.Scanned("tmdb:999:movie") { + t.Error("the item was not recorded as scanned") + } if _, res2, err := h.client.Lookup(context.Background(), item); err != nil { t.Fatalf("second Lookup: %v", err) - } else if !res2.Cached || res2.Reason != ReasonNoData { - t.Errorf("second result = %+v, want a cached no-data", res2) + } else if !res2.Cached || !res2.Skipped || res2.Reason != ReasonScanned { + t.Errorf("second result = %+v, want an answer from the scan record", res2) } if h.server.Count() != 1 { - t.Errorf("a cached 404 made a network call") + t.Errorf("a scanned 404 made a network call") } - // A 404 turns into a 200 the moment someone submits the timing, so it must - // expire and be asked again. - h.clock.Advance(15 * 24 * time.Hour) - if _, res3, err := h.client.Lookup(context.Background(), item); err != nil { + // A year later: past every TTL, and still not asked again. The miss TTL + // still expires the cached body, which is why the body is not trusted + // forever; it just no longer decides when a request is made. + h.clock.Advance(365 * 24 * time.Hour) + set3, res3, err := h.client.Lookup(context.Background(), item) + if err != nil { t.Fatalf("third Lookup: %v", err) - } else if res3.Cached { - t.Errorf("third result = %+v, want a fresh request after the miss TTL", res3) + } + if !res3.Skipped || res3.Status != 404 || len(set3.Segments) != 0 { + t.Errorf("third result = %+v, want the remembered no-data with no request", res3) + } + if h.server.Count() != 1 { + t.Errorf("server saw %d requests, want 1: only a re-scan asks again", h.server.Count()) + } + + // A re-scan does ask again. + if _, res4, err := h.client.LookupForced(context.Background(), item); err != nil { + t.Fatalf("LookupForced: %v", err) + } else if res4.Cached || res4.Skipped || res4.Reason != ReasonNoData { + t.Errorf("forced result = %+v, want a fresh request", res4) } if h.server.Count() != 2 { - t.Errorf("server saw %d requests, want 2 after the miss TTL expired", h.server.Count()) + t.Errorf("server saw %d requests, want 2 after a re-scan", h.server.Count()) } } -func TestLookup200UsesHitTTLNotMissTTL(t *testing.T) { +// An item that was scanned once is never asked about again, whatever the cache +// TTL says, and a re-scan is what replaces the answer: the 404 becomes a 200, +// the stored body is refreshed, and the next ordinary lookup serves the new one. +func TestLookupForcedRefreshesAScannedItem(t *testing.T) { h := newHarness(t, func(call int, w http.ResponseWriter, r *http.Request) { + if call == 1 { + js(w, 404, `{"error":"no data"}`) + return + } js(w, 200, sampleBody) }, func(cfg *config.TheIntroDB) { cfg.HitTTLDays = 30 @@ -450,31 +478,49 @@ func TestLookup200UsesHitTTLNotMissTTL(t *testing.T) { }) item := movieItem(550, 1470000) - if _, _, err := h.client.Lookup(context.Background(), item); err != nil { + + if _, res, err := h.client.Lookup(context.Background(), item); err != nil { t.Fatalf("Lookup: %v", err) + } else if res.Status != 404 { + t.Fatalf("first result = %+v, want the 404 the server sent", res) } - // 15 days is past MissTTLDays but inside HitTTLDays: a 200 must still be - // served from the ledger. - h.clock.Advance(15 * 24 * time.Hour) + // Way past the hit TTL: still no request, because it was scanned. + h.clock.Advance(400 * 24 * time.Hour) if _, res, err := h.client.Lookup(context.Background(), item); err != nil { t.Fatalf("Lookup: %v", err) - } else if !res.Cached { - t.Errorf("result = %+v, want a cached hit at 15 days", res) + } else if !res.Skipped { + t.Errorf("result = %+v, want it served from the scan record at 400 days", res) } if h.server.Count() != 1 { - t.Errorf("server saw %d requests, want 1", h.server.Count()) + t.Fatalf("server saw %d requests, want 1", h.server.Count()) } - // 31 days is past HitTTLDays. - h.clock.Advance(17 * 24 * time.Hour) - if _, res, err := h.client.Lookup(context.Background(), item); err != nil { + set, res, err := h.client.LookupForced(context.Background(), item) + if err != nil { + t.Fatalf("LookupForced: %v", err) + } + if res.Cached || res.Skipped || res.Status != 200 { + t.Errorf("forced result = %+v, want a fresh 200", res) + } + if !set.Has(model.SegmentIntro) || !set.Has(model.SegmentCredits) { + t.Errorf("forced segments = %+v, want the newly submitted intro and credits", set.Segments) + } + if h.server.Count() != 2 { + t.Errorf("server saw %d requests, want 2 after the re-scan", h.server.Count()) + } + if scan, found := h.ledger.Scan("tmdb:550:movie"); !found || scan.Status != 200 { + t.Errorf("scan record = %+v found=%v, want it refreshed to 200", scan, found) + } + + // The refreshed answer is what a later run serves, again without asking. + if _, res5, err := h.client.Lookup(context.Background(), item); err != nil { t.Fatalf("Lookup: %v", err) - } else if res.Cached { - t.Errorf("result = %+v, want a refresh past the hit TTL", res) + } else if !res5.Skipped || res5.Status != 200 { + t.Errorf("result = %+v, want the refreshed 200 from the scan record", res5) } if h.server.Count() != 2 { - t.Errorf("server saw %d requests, want 2", h.server.Count()) + t.Errorf("server saw %d requests, want 2: nothing asked again without a re-scan", h.server.Count()) } } @@ -520,6 +566,9 @@ func TestLookupBudgetRefusesTheRequest(t *testing.T) { if apiErr.IsTerminal() { t.Error("a spent budget is not terminal for the run: it resets at midnight") } + if !IsBudgetError(err) { + t.Error("a spent budget must be reported as one, so a scan pauses rather than failing") + } if !strings.Contains(apiErr.Error(), "budget") || !strings.Contains(apiErr.Error(), "00:00 UTC") { t.Errorf("budget error message = %q, want it to name the budget and the reset", apiErr.Error()) } @@ -701,6 +750,11 @@ func TestUsageLimitWaitIsNotClampedToFiveMinutes(t *testing.T) { if !errors.As(err, &apiErr) || apiErr.Kind != KindUsageLimit { t.Fatalf("error = %v, want a usage-limit *Error", err) } + if !IsBudgetError(err) { + // A scan pauses on this rather than failing, so the next run carries on + // instead of the nightly timer reporting an error every night. + t.Error("a spent daily allowance must be reported as a budget error so a scan pauses") + } if res.Reason != ReasonUsageLimit || res.Status != 429 { t.Errorf("result = %+v, want a 429 usage-limited", res) } diff --git a/internal/tidb/lookup.go b/internal/tidb/lookup.go index dc53be5..96cb3b8 100644 --- a/internal/tidb/lookup.go +++ b/internal/tidb/lookup.go @@ -10,6 +10,7 @@ import ( "strconv" "time" + "github.com/TheIntroDB/plex-sync/internal/ledger" "github.com/TheIntroDB/plex-sync/internal/model" ) @@ -24,11 +25,16 @@ type LookupResult struct { // Cached reports that the answer came from the ledger without a network // call. Cached bool `json:"cached"` - // Reason is one of ReasonHit, ReasonMiss, ReasonNoData, ReasonBudget, - // ReasonRateLimit, ReasonUsageLimit or ReasonError. + // Skipped reports that the answer came from the record of an earlier scan + // rather than from a cache entry that is still fresh: the item has been + // looked up before, so it was not asked about again. + Skipped bool `json:"skipped,omitempty"` + // Reason is one of ReasonHit, ReasonMiss, ReasonNoData, ReasonScanned, + // ReasonBudget, ReasonRateLimit, ReasonUsageLimit or ReasonError. // // It describes the ledger decision first: ReasonHit when a fresh cache - // entry answered, ReasonMiss when the network had to. ReasonNoData means + // entry answered, ReasonScanned when the item had already been scanned at + // some point, ReasonMiss when the network had to. ReasonNoData means // TheIntroDB holds nothing for the item, whether that came from the cache // or from a fresh 404; ReasonBudget, ReasonRateLimit and ReasonUsageLimit // mean no answer was obtained, and ReasonError means the lookup failed. @@ -54,15 +60,38 @@ func (r LookupResult) OK() bool { return r.Status == 200 || r.Status == 404 } // Lookup answers "what does TheIntroDB know about this item". // -// The order is deliberate: the ledger is consulted first and, while the answer -// is fresh, it is returned without any network call at all. Only then is the -// budget checked, the pacing floor and any hold applied, the request recorded -// and the API asked, with the real file length, which is what makes the answer -// cut-aware. +// The order is deliberate. First, the item's scan record: if it has been looked +// up before, the answer stored then is returned and no request is made, however +// long ago that was. A library of tens of thousands of items against a daily +// allowance of 500 or 1000 only ever finishes if each item is asked about once, +// and an item that was scanned is what "finished" means; the way to ask again +// is LookupForced, which is what a plan that names the item for a re-scan does. +// +// Second, the lookup cache, for a body written before this build recorded +// scans: while it is fresh it is served without a request. +// +// Only then is the budget checked, the pacing floor and any hold applied, the +// request recorded and the API asked, with the real file length, which is what +// makes the answer cut-aware. Every conclusive answer, 200 or 404, is recorded +// as a scan and cached. // // A miss is a miss: an empty SegmentSet comes back with ReasonNoData. No // segment is ever invented. func (c *Client) Lookup(ctx context.Context, item model.LibraryItem) (model.SegmentSet, LookupResult, error) { + return c.lookup(ctx, item, false) +} + +// LookupForced answers the same question while ignoring the record of the +// item's earlier scans, so the API is asked again whatever the ledger holds. +// +// This is what "re-scan this item" means, and it is the only thing that spends +// a request on an item that has already been scanned. A successful re-scan +// replaces the cached body and refreshes the scan record. +func (c *Client) LookupForced(ctx context.Context, item model.LibraryItem) (model.SegmentSet, LookupResult, error) { + return c.lookup(ctx, item, true) +} + +func (c *Client) lookup(ctx context.Context, item model.LibraryItem, force bool) (model.SegmentSet, LookupResult, error) { started := c.clock() empty := model.SegmentSet{Source: model.SourceTheIntroDB} @@ -88,38 +117,25 @@ func (c *Client) Lookup(ctx context.Context, item model.LibraryItem) (model.Segm now := c.clock() - if c.ledger != nil { - if cached, found := c.ledger.Lookup(key); found && cached.Fresh(now) { - switch cached.Status { - case 200: - set, err := ParseSegments(cached.Body) - if err == nil { - c.note(CachedData) - remaining, known := c.currentRemaining() - return set, LookupResult{ - Status: 200, - Cached: true, - Reason: ReasonHit, - Remaining: remaining, - RemainingKnown: known, - Elapsed: c.clock().Sub(started), - Key: key, - }, nil - } - // A body we can no longer parse is not a reason to fail the - // run: fall through and ask again. - case 404: - c.note(CachedNoData) - remaining, known := c.currentRemaining() - return empty, LookupResult{ - Status: 404, - Cached: true, - Reason: ReasonNoData, - Remaining: remaining, - RemainingKnown: known, - Elapsed: c.clock().Sub(started), - Key: key, - }, nil + if c.ledger != nil && !force { + cached, haveBody := c.ledger.Lookup(key) + + // Already scanned: answer from what was stored then, without a + // request. The scan record is what says so, so a body whose cache TTL + // has run out is still served rather than fetched again. + if scanned, haveScan := c.ledger.Scan(key); haveScan && haveBody { + if set, result, ok := c.serveStored(key, cached, scanned.Status, true, started); ok { + return set, result, nil + } + } + + // No scan record yet, but a body an older build stored may still be + // fresh. Serve it, and record the scan so the next run skips the item + // rather than coming back to it when the TTL runs out. + if haveBody && cached.Fresh(now) { + if set, result, ok := c.serveStored(key, cached, cached.Status, false, started); ok { + _ = c.ledger.RecordScan(key, cached.Status, string(item.Kind)) + return set, result, nil } } } @@ -148,13 +164,17 @@ func (c *Client) Lookup(ctx context.Context, item model.LibraryItem) (model.Segm return empty, result, perr } c.store(key, 200, string(resp.Body), item) + c.recordScan(key, 200, item) c.note(Data) return set, result, nil case 404: - // Cached for MissTTLDays only: a 404 becomes a 200 the moment someone - // submits the timing, so it must expire. + // The body is cached for MissTTLDays because a 404 becomes a 200 the + // moment someone submits the timing, so the body must expire. The scan + // record does not: the item has been asked about, and asking again is + // a re-scan rather than something time does on its own. c.store(key, 404, string(resp.Body), item) + c.recordScan(key, 404, item) c.note(NoData) result.Reason = ReasonNoData return empty, result, nil @@ -265,6 +285,74 @@ func (c *Client) buildQuery(item model.LibraryItem) url.Values { return q } +// serveStored turns a stored answer into a result, with no request. The bool +// reports whether the stored body could be used; a body this build can no +// longer parse is not a reason to fail, so the caller falls through and asks +// again. +// +// skipped says the answer came from the record of an earlier scan rather than +// from a cache entry that is still fresh, which is what the status output and +// the survey report differently: one is a run that has nothing left to ask, the +// other is a cache still doing its job. +func (c *Client) serveStored( + key string, + cached ledger.CachedLookup, + status int, + skipped bool, + started time.Time, +) (model.SegmentSet, LookupResult, bool) { + empty := model.SegmentSet{Source: model.SourceTheIntroDB} + + reason := ReasonHit + note := CachedData + switch status { + case 200: + case 404: + reason, note = ReasonNoData, CachedNoData + default: + return empty, LookupResult{}, false + } + if skipped { + reason = ReasonScanned + if status == 404 { + note = SkippedNoData + } else { + note = SkippedData + } + } + + set := empty + if status == 200 { + parsed, err := ParseSegments(cached.Body) + if err != nil { + return empty, LookupResult{}, false + } + set = parsed + } + + c.note(note) + remaining, known := c.currentRemaining() + return set, LookupResult{ + Status: status, + Cached: true, + Skipped: skipped, + Reason: reason, + Remaining: remaining, + RemainingKnown: known, + Elapsed: c.clock().Sub(started), + Key: key, + }, true +} + +// recordScan remembers that an item has been looked up, so that a later run +// spends its requests on the items it has never seen. +func (c *Client) recordScan(key string, status int, item model.LibraryItem) { + if c.ledger == nil { + return + } + _ = c.ledger.RecordScan(key, status, string(item.Kind)) +} + // store caches an answer: 200s for HitTTLDays, 404s for MissTTLDays. func (c *Client) store(key string, status int, body string, item model.LibraryItem) { if c.ledger == nil { @@ -290,6 +378,8 @@ const ( NoData CachedData CachedNoData + SkippedData + SkippedNoData RateLimited UsageLimited Failed @@ -309,6 +399,14 @@ func (c *Client) note(kind noteKind) { case CachedNoData: c.cacheHits++ c.noData++ + case SkippedData: + c.cacheHits++ + c.skipped++ + c.data++ + case SkippedNoData: + c.cacheHits++ + c.skipped++ + c.noData++ case RateLimited: c.rateLimited++ c.errs++ diff --git a/internal/tui/model.go b/internal/tui/model.go index 1643437..348693e 100644 --- a/internal/tui/model.go +++ b/internal/tui/model.go @@ -95,6 +95,9 @@ type Model struct { // listOffset scrolls the library and plan lists. listOffset int + // planCursor is the row the preview screen's selection is on, as an index + // into the plan's work. + planCursor int // pending counts the loads the current busy stage is waiting for, and busy // names that stage. A refresh is two loads (the ledger and the services), @@ -209,6 +212,10 @@ func (m *Model) loadInventory() tea.Cmd { // runPlan plans. It reports progress into the program so the interface stays // responsive: a plan is one lookup per item, which is minutes of work on a // large library. +// +// Items marked for a re-scan on the preview screen are carried into the plan, so +// pressing p again is what makes a marked item actually be asked about again: +// nothing is re-scanned on its own. func (m *Model) runPlan() tea.Cmd { return func() tea.Msg { opts := sync.Options{ @@ -221,6 +228,9 @@ func (m *Model) runPlan() tea.Cmd { } }, } + if m.result != nil && m.result.Plan.Selection != nil { + opts.Rescan = append(opts.Rescan, m.result.Plan.Selection.Rescan...) + } result, err := m.runner.Plan(m.ctx, opts) return planMsg{result: result, err: err} } @@ -238,6 +248,11 @@ func (m *Model) runApply() tea.Cmd { Limit: m.opts.Limit, Progress: func(event sync.Event) { m.sendProgress(event) }, } + // Only the items left on are written. The plan says what could change, + // the preview screen's selection says what was agreed to. + if selection := m.result.Plan.Selection; selection != nil { + opts.Deselected = append(opts.Deselected, selection.Unselected...) + } err := m.runner.Apply(m.ctx, m.result, opts) return applyMsg{result: m.result, err: err} } @@ -333,7 +348,9 @@ func (m *Model) Update(msg tea.Msg) (tea.Model, tea.Cmd) { m.result = msg.result m.screen = screenPlan m.listOffset = 0 - m.setStatus(fmt.Sprintf("plan ready: %d item(s) to change", len(m.result.Plan.Work()))) + m.planCursor = 0 + m.setStatus(fmt.Sprintf("plan ready: %d item(s) to change, %d selected", + len(m.result.Plan.Work()), len(m.result.Plan.SelectedWork()))) return m, m.loadStatus() case applyMsg: @@ -454,6 +471,38 @@ func (m *Model) handleKey(msg tea.KeyMsg) (tea.Model, tea.Cmd) { } } + // On the preview screen the arrow keys move a cursor over the items and + // space turns the one under it on or off. That is what turns a plan from a + // report into a decision: only the items left on are written. + if m.screen == screenPlan && m.result != nil && m.planLen() > 0 { + switch msg.String() { + case "up", "k": + m.movePlanCursor(-1) + return m, nil + case "down", "j": + m.movePlanCursor(1) + return m, nil + case "home", "g": + m.setPlanCursor(0) + return m, nil + case "end", "G": + m.setPlanCursor(m.planLen() - 1) + return m, nil + case " ", "enter": + m.togglePlanItem() + return m, nil + case "A": + m.selectPlanItems(true) + return m, nil + case "N": + m.selectPlanItems(false) + return m, nil + case "R": + m.togglePlanRescan() + return m, nil + } + } + switch msg.String() { case "q", "ctrl+c": m.quit = true @@ -494,7 +543,7 @@ func (m *Model) handleKey(msg tea.KeyMsg) (tea.Model, tea.Cmd) { m.setStatus("planning: this makes one lookup per item, so it can take a while") return m, m.runPlan() case "a": - if m.result == nil || len(m.result.Plan.Work()) == 0 { + if m.result == nil || len(m.result.Plan.SelectedWork()) == 0 { m.setError(fmt.Errorf("nothing to apply: press p to plan first")) return m, nil } @@ -524,13 +573,123 @@ func (m *Model) handleKey(msg tea.KeyMsg) (tea.Model, tea.Cmd) { m.listOffset = 0 return m, nil case "?": - m.setStatus("1-5 screens, tab next, r refresh, l library, p plan, a apply, u undo, " + + m.setStatus("1-5 screens, tab next, r refresh, l library, p plan, a apply, u undo; " + + "on Preview: up/down move, space select, A all, N none, R re-scan; " + "on Settings: up/down move, enter change, q quit") return m, nil } return m, nil } +// --- the preview screen's selection ---------------------------------------- + +// planLen is how many rows the preview screen has to move over. +func (m *Model) planLen() int { + if m.result == nil { + return 0 + } + return len(m.result.Plan.Work()) +} + +// setPlanCursor moves the preview cursor to a row and keeps it on screen. +func (m *Model) setPlanCursor(index int) { + n := m.planLen() + if n == 0 { + m.planCursor = 0 + return + } + if index < 0 { + index = 0 + } + if index >= n { + index = n - 1 + } + m.planCursor = index + m.keepPlanCursorVisible(n) +} + +// movePlanCursor steps the preview cursor by delta, stopping at either end +// rather than wrapping, so a held key cannot run away from the row in view. +func (m *Model) movePlanCursor(delta int) { + m.setPlanCursor(m.planCursor + delta) +} + +// keepPlanCursorVisible scrolls the list so the selected row is on the page. +func (m *Model) keepPlanCursorVisible(n int) { + size := m.pageSize() + if m.planCursor < m.listOffset { + m.listOffset = m.planCursor + } + if m.planCursor >= m.listOffset+size { + m.listOffset = m.planCursor - size + 1 + } + m.clampOffset(n) +} + +// togglePlanItem turns the item under the cursor on or off. An item that is off +// stays in the preview and is simply not written, so nothing is hidden. +func (m *Model) togglePlanItem() { + work := m.result.Plan.Work() + if m.planCursor < 0 || m.planCursor >= len(work) { + return + } + ratingKey := work[m.planCursor].Item.RatingKey + selection := m.result.Plan.EnsureSelection() + selection.Select(ratingKey, !selection.Selected(ratingKey)) + m.recountPlan() +} + +// selectPlanItems turns every item in the plan on or off. +func (m *Model) selectPlanItems(selected bool) { + if m.result == nil { + return + } + selection := m.result.Plan.EnsureSelection() + for _, item := range m.result.Plan.Work() { + selection.Select(item.Item.RatingKey, selected) + } + m.recountPlan() +} + +// togglePlanRescan marks the item under the cursor to be asked about again. +// +// The mark takes effect on the next plan, because that is when lookups happen: +// the status line says so rather than implying the answer has already changed. +func (m *Model) togglePlanRescan() { + work := m.result.Plan.Work() + if m.planCursor < 0 || m.planCursor >= len(work) { + return + } + item := work[m.planCursor] + key, ok := item.Item.LookupKey() + if !ok { + m.setError(fmt.Errorf("%s has no TMDb, IMDb or TVDb id, so it cannot be looked up", + item.Item.Label())) + return + } + selection := m.result.Plan.EnsureSelection() + marked := !selection.RescanKeys()[key] + selection.MarkRescan(key, marked) + if marked { + m.setStatus(fmt.Sprintf("marked %s for a re-scan: press p to plan again and ask for it", + item.Item.Label())) + return + } + m.setStatus(fmt.Sprintf("%s will not be re-scanned", item.Item.Label())) +} + +// recountPlan reports how much of the plan is still selected. +func (m *Model) recountPlan() { + work := m.result.Plan.Work() + selected := len(m.result.Plan.SelectedWork()) + if leftOut := len(work) - selected; leftOut > 0 { + m.setStatus(fmt.Sprintf("%d of %d item(s) selected, %d left out", + selected, len(work), leftOut)) + return + } + m.setStatus(fmt.Sprintf("all %d item(s) selected", len(work))) +} + // --- small helpers --------------------------------------------------------- func (m *Model) setStatus(text string) { diff --git a/internal/tui/plan_test.go b/internal/tui/plan_test.go new file mode 100644 index 0000000..25ecf0b --- /dev/null +++ b/internal/tui/plan_test.go @@ -0,0 +1,193 @@ +package tui + +import ( + "fmt" + "strings" + "testing" + + "github.com/TheIntroDB/plex-sync/internal/model" + "github.com/TheIntroDB/plex-sync/internal/sync" +) + +// withPlan puts a plan of n items on the model and shows the preview screen, so +// the selection keys have something to act on without a library or a server. +func withPlan(t *testing.T, n int) *Model { + t.Helper() + m := newTestModel(t) + + var plan model.Plan + for i := 1; i <= n; i++ { + plan.Items = append(plan.Items, model.ItemPlan{ + Item: model.LibraryItem{ + RatingKey: i, + Title: fmt.Sprintf("episode %d", i), + Kind: model.KindEpisode, + Season: intPtr(1), + Episode: intPtr(i), + IDs: model.ExternalIDs{TMDB: intPtr(1000 + i)}, + }, + Add: []model.Marker{{ + Text: model.MarkerIntro, StartMS: 0, EndMS: 1000, + Source: string(model.SourceTheIntroDB), + }}, + Reason: "add", + }) + } + m.result = &sync.Result{Plan: plan} + m.screen = screenPlan + return m +} + +func intPtr(v int) *int { return &v } + +// pressKeys sends keys to the interface, failing if one of them quits it. +func pressKeys(t *testing.T, m *Model, keys ...string) { + t.Helper() + for _, key := range keys { + if _, _ = m.handleKey(keyMsg(key)); m.quit { + t.Fatalf("key %q quit the interface", key) + } + } +} + +func TestArrowsMoveThePlanCursor(t *testing.T) { + m := withPlan(t, 3) + + if m.planCursor != 0 { + t.Fatalf("cursor starts at %d, want 0", m.planCursor) + } + pressKeys(t, m, "down", "down") + if m.planCursor != 2 { + t.Errorf("cursor after two downs = %d, want 2", m.planCursor) + } + // It stops at the ends rather than wrapping, so a held key cannot come back + // round to the top without the person noticing. + pressKeys(t, m, "down", "down") + if m.planCursor != 2 { + t.Errorf("cursor past the last row = %d, want 2", m.planCursor) + } + pressKeys(t, m, "up") + if m.planCursor != 1 { + t.Errorf("cursor after one up = %d, want 1", m.planCursor) + } + pressKeys(t, m, "up", "up") + if m.planCursor != 0 { + t.Errorf("cursor past the first row = %d, want 0", m.planCursor) + } + pressKeys(t, m, "end") + if m.planCursor != 2 { + t.Errorf("cursor after end = %d, want 2", m.planCursor) + } + pressKeys(t, m, "home") + if m.planCursor != 0 { + t.Errorf("cursor after home = %d, want 0", m.planCursor) + } +} + +func TestSpaceSelectsAndUnselectsTheItemUnderTheCursor(t *testing.T) { + m := withPlan(t, 3) + + pressKeys(t, m, "down", " ") // item 2 + if len(m.result.Plan.SelectedWork()) != 2 { + t.Fatalf("selected work = %d, want 2 after turning one off", + len(m.result.Plan.SelectedWork())) + } + if m.result.Plan.Selection.Selected(2) { + t.Error("item 2 is still selected") + } + if !m.result.Plan.Selection.Selected(1) || !m.result.Plan.Selection.Selected(3) { + t.Error("deselecting one item turned off another") + } + if !strings.Contains(m.status, "1 left out") { + t.Errorf("status = %q, want it to say how many were left out", m.status) + } + + // The same key turns it back on, which is what unselect means. + pressKeys(t, m, " ") + if len(m.result.Plan.SelectedWork()) != 3 { + t.Errorf("selected work = %d, want 3 after turning it back on", + len(m.result.Plan.SelectedWork())) + } +} + +func TestSelectAllAndNone(t *testing.T) { + m := withPlan(t, 3) + + pressKeys(t, m, "N") + if len(m.result.Plan.SelectedWork()) != 0 { + t.Errorf("selected work = %d, want none after N", len(m.result.Plan.SelectedWork())) + } + if !strings.Contains(m.status, "3 left out") { + t.Errorf("status = %q, want it to say all three were left out", m.status) + } + + pressKeys(t, m, "A") + if len(m.result.Plan.SelectedWork()) != 3 { + t.Errorf("selected work = %d, want all three after A", len(m.result.Plan.SelectedWork())) + } +} + +func TestRescanIsMarkedAndShown(t *testing.T) { + m := withPlan(t, 2) + + pressKeys(t, m, "R") + keys := m.result.Plan.Selection.RescanKeys() + if !keys["tmdb:1001:1:1"] { + t.Fatalf("rescan keys = %v, want the first item's lookup key", keys) + } + if !strings.Contains(m.status, "press p to plan again") { + t.Errorf("status = %q, want it to say the re-scan happens on the next plan", m.status) + } + if !strings.Contains(m.View(), "[re-scan]") { + t.Error("the preview does not show that an item is marked for a re-scan") + } + + // Pressing it again unmarks. + pressKeys(t, m, "R") + if len(m.result.Plan.Selection.RescanKeys()) != 0 { + t.Errorf("rescan keys = %v, want none after unmarking", + m.result.Plan.Selection.RescanKeys()) + } +} + +func TestThePreviewMarksTheCursorAndTheSelection(t *testing.T) { + m := withPlan(t, 3) + + out := m.View() + if !strings.Contains(out, "> [x]") { + t.Errorf("the preview does not mark the cursor row:\n%s", out) + } + + pressKeys(t, m, "down", "down", " ") + out = m.View() + if !strings.Contains(out, "[ ]") { + t.Errorf("the preview does not show an unselected item:\n%s", out) + } + if !strings.Contains(out, "3 item(s) to change, 2 selected") { + t.Errorf("the preview does not count the selection:\n%s", out) + } +} + +func TestThePlanScreenKeepsItsCursorOnScreen(t *testing.T) { + m := withPlan(t, 60) + m.height = 20 + + for i := 0; i < 40; i++ { + pressKeys(t, m, "down") + } + start, end := m.visible(m.planLen()) + if m.planCursor < start || m.planCursor >= end { + t.Errorf("cursor %d is outside the visible rows %d-%d", m.planCursor, start, end) + } +} + +func TestThePreviewKeysDoNothingWithoutAPlan(t *testing.T) { + m := newTestModel(t) + m.screen = screenPlan + + // Nothing here may panic or write: there is no plan to select from. + pressKeys(t, m, "down", " ", "A", "N", "R") + if m.result != nil { + t.Error("a plan appeared from nowhere") + } +} diff --git a/internal/tui/view.go b/internal/tui/view.go index 8cdb141..f20d6f4 100644 --- a/internal/tui/view.go +++ b/internal/tui/view.go @@ -128,6 +128,10 @@ func (m *Model) statusScreen() string { if m.stats != nil { b.WriteString(fmt.Sprintf(" all time %d request(s), %d lookup(s), %d hit(s)\n", m.stats.RequestsTotal, m.stats.Lookups, m.stats.LookupHits)) + if m.stats.Scanned > 0 { + b.WriteString(fmt.Sprintf(" scanned %d item(s) (%d with data, %d without)\n", + m.stats.Scanned, m.stats.ScannedWithData, m.stats.ScannedNoData)) + } } b.WriteString("\n" + styleTitle.Render("Markers written") + "\n") @@ -222,25 +226,52 @@ func (m *Model) planScreen() string { } res := m.result work := res.Plan.Work() + selected := len(res.Plan.SelectedWork()) + rescans := res.Plan.Selection.RescanKeys() var b strings.Builder b.WriteString(styleTitle.Render("Preview") + "\n") - b.WriteString(fmt.Sprintf(" examined %d item(s): %d with data, %d without, %d cached, %d lookup(s)\n", - res.Survey.Items, res.Survey.WithData, res.Survey.NoData, res.Survey.Cached, res.Survey.Lookups)) - b.WriteString(fmt.Sprintf(" policy %s, %d item(s) to change\n\n", - res.Plan.Options.Policy, len(work))) + b.WriteString(fmt.Sprintf(" examined %d item(s): %d with data, %d without, %d already scanned, %d lookup(s)\n", + res.Survey.Items, res.Survey.WithData, res.Survey.NoData, res.Survey.Skipped, res.Survey.Lookups)) + b.WriteString(fmt.Sprintf(" policy %s, %d item(s) to change, %d selected\n", + res.Plan.Options.Policy, len(work), selected)) + if res.Survey.Paused { + b.WriteString(" " + styleWarn.Render(fmt.Sprintf( + "paused: the day's allowance was spent, %d item(s) still to scan; the next run continues here", + res.Survey.Remaining)) + "\n") + } + b.WriteString("\n") if len(work) == 0 { b.WriteString(styleGood.Render(" Nothing to do.") + "\n") } else { start, end := m.visible(len(work)) - for _, item := range work[start:end] { - b.WriteString(fmt.Sprintf(" %-44s %-8s %s\n", - truncate(item.Item.Label(), 44), item.Reason, describeItem(item))) + for i := start; i < end; i++ { + item := work[i] + + // The cursor is a marker rather than only a colour, so what is + // selected survives being read in a terminal without any. + cursor := " " + if i == m.planCursor { + cursor = styleKey.Render("> ") + } + box := "[x]" + if !res.Plan.Selection.Selected(item.Item.RatingKey) { + box = "[ ]" + } + flag := "" + if key, ok := item.Item.LookupKey(); ok && rescans[key] { + flag = " " + styleWarn.Render("[re-scan]") + } + b.WriteString(fmt.Sprintf(" %s%s %-42s %-8s %s%s\n", + cursor, box, truncate(item.Item.Label(), 42), item.Reason, + describeItem(item), flag)) } if end < len(work) { b.WriteString(styleDim.Render(fmt.Sprintf(" ... %d more\n", len(work)-end))) } + b.WriteString("\n" + styleDim.Render( + " space select A all N none R re-scan (then p to ask again)") + "\n") } if len(res.Survey.SkipReasons) > 0 { @@ -397,8 +428,10 @@ func (m *Model) confirmation() string { work := 0 added := 0 if m.result != nil { - work = len(m.result.Plan.Work()) - for _, item := range m.result.Plan.Work() { + // Only what is selected is written, so the confirmation counts + // what will actually happen rather than what the plan found. + work = len(m.result.Plan.SelectedWork()) + for _, item := range m.result.Plan.SelectedWork() { added += len(item.Add) } } @@ -431,6 +464,9 @@ func (m *Model) footer() string { if m.screen == screenSettings { keys = "up/down move enter change tab next q quit" } + if m.screen == screenPlan { + keys = "up/down move space select A all N none R re-scan p plan a write q quit" + } b.WriteString(styleDim.Render(" " + keys)) return b.String() }