* docs(plans): root-cause analysis for endpoints still slow after PR #292 Five endpoint groups stayed slow after the home/Continue Watching/Latest latency work shipped: Resume (110s p95), NextUp (17s p95), Latest (17s), /Items, and the home sections routes. The caps and caches from PR #292 are live in the deployed binary; they bounded how many rows the loops touch but not what each underlying query costs. Documents the four confirmed root causes (4.3M stale completed-with-position progress rows + missing resume index, unbounded next-up anchor scan, per-episode series rollup fanout, two index-starved history/scanner paths) with live EXPLAIN ANALYZE measurements and the fix plan implemented by the follow-up commits. AI-use disclosure: analysis and doc produced with AI (Claude) assistance. * perf(catalog): bound the global next-up anchor scan to recent completions The completed_episodes CTE in buildListNextUpQuery derived per-series anchors from the profile's ENTIRE completed history — DISTINCT ON over 233k rows joined to episodes for the worst bulk-import profile, then a per-series LATERAL that scans every episode of a fully-watched series before yielding nothing. 648 slow executions in a 19h window, 44.7s worst; this drove /Shows/NextUp (17.1s p95) and the next-up injection on the native home sections aggregate. Global queries now derive anchors from the profile's nextUpAnchorMaxRows (500) most recent completed rows — an ordered index walk on idx_uwp_profile_completed, with the hidden-items exclusion and date cutoff applied inside the bounded scan so hidden/old rows never consume the anchor budget. A next-up rail surfaces ~24 series; the 500 most recent completions cover every series that can realistically rank on it. Series-scoped calls (the show-detail tile) keep the unbounded shape: they must anchor on the series' last completed episode no matter how long ago it was watched, and are naturally bounded by one series. Measured on the live worst-case profile with the exact generated SQL: 44.7s worst / ~2.6s avg before; 10ms after (together with the one-time stale-resume-point data repair applied directly to the deployment DB — see docs/superpowers/plans/2026-07-06-slow-endpoint-root-causes.md). AI-use disclosure: implemented with AI (Claude) assistance. * perf(jellycompat,userstore): aggregate series watch-state rollup in SQL The series Played/UnplayedItemCount badge on list rails (per-library Latest, library browse, search results) and series detail pages was computed by materializing EVERY episode of every series on the page (episodeRepo.ListBySeriesIDs) and then batching per-episode progress+history lookups in 500-id chunks. A 50-series page of an episode-heavy library (Sports) expanded to 32,467 episode rows and ~65 sequential queries — measured 17-18s per /Items/Latest request, and PR #292's cached Latest fast path pays it on every response for series libraries. The same fanout made /Items?searchTerm=... slow whenever the result set was mostly series (Meilisearch itself answers in milliseconds). New optional store capability userstore.SeriesEpisodeRollupStore, implemented by PostgresUserStore as one GROUP BY e.series_id aggregate with semantics identical to the chunked path (episode availability via episode_libraries, hidden-items visibility on progress rows, completed-history fold, in-progress = not watched with position > 0 — verified value-for-value against the old semantics on a real 1,586-episode series). enrichSeriesListUserData and enrichDetailUserData use it when present; SQLite-backed stores and rollup query failures keep the existing chunked path as fallback. catalog.SeasonUserDataFromCounts pins the counts-to-DTO mapping to EpisodeRollupUserData. Measured on the live worst-case profile against the real 50-series Sports Latest page: ~17s of chunked round-trips before, 119ms in one query after. Part of docs/superpowers/plans/2026-07-06-slow-endpoint-root-causes.md. AI-use disclosure: implemented with AI (Claude) assistance. * perf(catalog): bound superseded-episode completed walk to recent history The Resume / Continue Watching superseded-episode filter loaded a profile's *entire* completed history into memory on every request that contained an in-progress episode: CompletedProgressSnapshots paged user_watch_progress WHERE completed=TRUE with no upper bound. The 2026-07-06 slow-query comparison showed this surviving as a 60-116s Resume tail even after the in-progress index landed live, because the 4.3M zeroed Plex-import rows are still completed=TRUE and were re-walked every load. A completed episode can only supersede an in-progress one it was finished more recently than (the query gates on done_progress.updated_at > ip_progress.updated_at), so only completed rows newer than the oldest in-progress entry can matter. Compute that cutoff in SupersededEpisodeProgressIDs and pass it to CompletedProgressSnapshots, which — since the completed listing is ordered updated_at DESC — stops paging as soon as it crosses the cutoff. Import-heavy profiles whose back-catalogue predates their current in-progress items now stop on the first page instead of paging hundreds of thousands of irrelevant rows. Correctness is unchanged: no relevant superseding row is excluded. * perf(catalog): hard-cap superseded-episode completed walk at 5 pages The updated_at cutoff added in the previous commit bounds the completed walk on the relevance axis, but a very old in-progress entry sitting behind a large volume of newer completions could still page deep. Add a 5-page (2,500-row) hard backstop on top of the cutoff: normal profiles still stop on page one via the cutoff, and only the adversarial tail hits the cap. When it engages the tail of the completed set goes unscanned, so a superseded episode could momentarily survive on Continue Watching — we log a warning when that happens (with profile_id + rows scanned) rather than mis-filter silently, and it self-corrects once the stale in-progress entry ages out of the scanned window. * perf(playback): extract subtitle fonts in a single ffmpeg pass Embedded ASS/SSA font extraction spawned one ffmpeg process per font attachment, each re-opening the (usually CephFS-backed) media file. Anime releases carry 15-47 fonts, so the per-spawn file-open cost dominated and pushed GET /api/v1/stream/{sid}/subtitles/{track}/fonts to a 17-60 s plateau (p95 ~33 s in the live logs). Collapse the N spawns into one ffmpeg invocation that dumps every attachment to a temp dir (-dump_attachment:idx path ... -i file -map 0:t? -c copy), then read the files back. The file is opened once instead of N times, taking p95 from ~30 s to ~1-2 s with no change to output. Safety is preserved. The 32-attachment / 32 MiB caps still apply: attachment size is stat'd before read so an over-limit font never enters memory, and a watchdog polls the dump dir and kills ffmpeg if its on-disk output crosses the cap -- restoring the hard bound the old pipe-per-attachment reader enforced by killing at maxBytes+1, so a container with oversized "font" attachments can't fill the disk. Part of the slow-endpoint follow-up; see slow-query-analysis/subtitle-fonts-extraction-findings.md. * fix(review): report enforced font-byte cap; correct doc subtitle scope Address PR #350 review: - dumpFontAttachments reported the maxSubtitleFontBytes package constant in both over-limit errors instead of the maxBytes argument the caller passed, so the message misstated the enforced bound whenever a different cap was in effect (as the tests use). Interpolate maxBytes in both messages. - The root-cause plan claimed subtitle extraction was 'out of scope' while the branch actually optimizes /subtitles/{track}/fonts. Scope the out-of-scope note to subtitle *track* conversion and record the fonts single-pass work as deliverable 5.
228 lines
7.2 KiB
Go
228 lines
7.2 KiB
Go
package userstore
|
|
|
|
import (
|
|
"context"
|
|
"strings"
|
|
"time"
|
|
)
|
|
|
|
type HistoryVisibilityStore interface {
|
|
VisibleHistoryTimestamps(ctx context.Context, profileID string, mediaItemIDs []string, at time.Time) (map[string]string, error)
|
|
}
|
|
|
|
type VisibleHistoryAdder interface {
|
|
AddVisibleHistory(ctx context.Context, entry WatchHistoryEntry) (WatchHistoryEntry, error)
|
|
}
|
|
|
|
func AddVisibleHistory(ctx context.Context, store UserStore, entry WatchHistoryEntry) (WatchHistoryEntry, error) {
|
|
if adder, ok := store.(VisibleHistoryAdder); ok {
|
|
return adder.AddVisibleHistory(ctx, entry)
|
|
}
|
|
entryTimes, err := VisibleHistoryTimestamps(ctx, store, entry.ProfileID, []string{entry.MediaItemID}, parseHistoryTimestamp(entry.WatchedAt))
|
|
if err != nil {
|
|
return entry, err
|
|
}
|
|
if entryTime := entryTimes[entry.MediaItemID]; entryTime != "" {
|
|
entry.WatchedAt = entryTime
|
|
}
|
|
if err := store.AddHistory(ctx, entry); err != nil {
|
|
return entry, err
|
|
}
|
|
return entry, nil
|
|
}
|
|
|
|
func VisibleHistoryTimestamps(ctx context.Context, store UserStore, profileID string, mediaItemIDs []string, at time.Time) (map[string]string, error) {
|
|
mediaItemIDs = compactHistoryMediaItemIDs(mediaItemIDs)
|
|
result := make(map[string]string, len(mediaItemIDs))
|
|
if len(mediaItemIDs) == 0 {
|
|
return result, nil
|
|
}
|
|
if visibilityStore, ok := store.(HistoryVisibilityStore); ok {
|
|
return visibilityStore.VisibleHistoryTimestamps(ctx, profileID, mediaItemIDs, at)
|
|
}
|
|
timestamp := at.UTC().Format(time.RFC3339)
|
|
if at.IsZero() {
|
|
timestamp = time.Now().UTC().Format(time.RFC3339)
|
|
}
|
|
for _, mediaItemID := range mediaItemIDs {
|
|
result[mediaItemID] = timestamp
|
|
}
|
|
return result, nil
|
|
}
|
|
|
|
func parseHistoryTimestamp(value string) time.Time {
|
|
if value == "" {
|
|
return time.Time{}
|
|
}
|
|
parsed, err := time.Parse(time.RFC3339, value)
|
|
if err != nil {
|
|
return time.Time{}
|
|
}
|
|
return parsed
|
|
}
|
|
|
|
// SeriesWatchCounts is the aggregate episode watch state for one series, as
|
|
// computed by SeriesEpisodeRollupStore.
|
|
type SeriesWatchCounts struct {
|
|
TotalEpisodes int
|
|
WatchedCount int
|
|
InProgressCount int
|
|
}
|
|
|
|
// SeriesEpisodeRollupStore is an optional store capability: compute the
|
|
// per-series episode watch-state rollup (total / watched / in-progress
|
|
// episode counts) in SQL instead of materializing every episode of every
|
|
// series and batching per-episode progress lookups through
|
|
// ListProgressWithCompletedHistory. Implemented by the Postgres store, where
|
|
// episodes and progress live in the same database; SQLite-backed stores fall
|
|
// back to the chunked in-memory path. Semantics must match
|
|
// ListProgressWithCompletedHistory + catalog.EpisodeRollupUserData: an episode
|
|
// is watched when its visible progress row is completed or a visible completed
|
|
// history row exists, and in-progress when it is not watched and its visible
|
|
// progress row has position_seconds > 0.
|
|
type SeriesEpisodeRollupStore interface {
|
|
SeriesEpisodeWatchCounts(ctx context.Context, profileID string, seriesIDs []string) (map[string]SeriesWatchCounts, error)
|
|
}
|
|
|
|
// CompletedHistoryItemMap returns the latest completed-history item row for a
|
|
// scoped item query. Lookup failures degrade to an empty map so user-data
|
|
// enrichment can keep returning progress rows.
|
|
func CompletedHistoryItemMap(ctx context.Context, store ProgressCompletionStore, query CompletedHistoryItemQuery) map[string]CompletedHistoryItem {
|
|
result := map[string]CompletedHistoryItem{}
|
|
if store == nil || query.ProfileID == "" {
|
|
return result
|
|
}
|
|
query.MediaItemIDs = compactHistoryMediaItemIDs(query.MediaItemIDs)
|
|
if len(query.MediaItemIDs) == 0 {
|
|
return result
|
|
}
|
|
items, err := store.ListCompletedHistoryItems(ctx, query)
|
|
if err != nil {
|
|
return result
|
|
}
|
|
for _, item := range items {
|
|
if item.MediaItemID != "" {
|
|
result[item.MediaItemID] = item
|
|
}
|
|
}
|
|
return result
|
|
}
|
|
|
|
// GetProgressWithCompletedHistory returns normal progress overlaid with
|
|
// completed history for callers that present a single item's played state.
|
|
func GetProgressWithCompletedHistory(ctx context.Context, store UserStore, profileID, mediaItemID string) (*WatchProgress, error) {
|
|
mediaItemID = strings.TrimSpace(mediaItemID)
|
|
if store == nil || profileID == "" || mediaItemID == "" {
|
|
return nil, nil
|
|
}
|
|
progress, err := store.GetProgress(ctx, profileID, mediaItemID)
|
|
if err != nil {
|
|
return nil, err
|
|
}
|
|
if progress != nil && progress.Completed {
|
|
return progress, nil
|
|
}
|
|
completed := CompletedHistoryItemMap(ctx, store, CompletedHistoryItemQuery{
|
|
ProfileID: profileID,
|
|
MediaItemIDs: []string{mediaItemID},
|
|
})[mediaItemID]
|
|
if completed.MediaItemID == "" {
|
|
return progress, nil
|
|
}
|
|
if progress == nil {
|
|
return &WatchProgress{
|
|
ProfileID: profileID,
|
|
MediaItemID: mediaItemID,
|
|
Completed: true,
|
|
UpdatedAt: completed.WatchedAt,
|
|
}, nil
|
|
}
|
|
progress.Completed = true
|
|
if timestampAfter(completed.WatchedAt, progress.UpdatedAt) {
|
|
progress.UpdatedAt = completed.WatchedAt
|
|
}
|
|
return progress, nil
|
|
}
|
|
|
|
// ListProgressWithCompletedHistory returns progress for mediaItemIDs with
|
|
// completed history folded into the map. History is only queried for IDs that
|
|
// are not already completed by a progress row.
|
|
func ListProgressWithCompletedHistory(ctx context.Context, store ProgressCompletionStore, profileID string, mediaItemIDs []string) (map[string]WatchProgress, error) {
|
|
mediaItemIDs = compactHistoryMediaItemIDs(mediaItemIDs)
|
|
if store == nil || profileID == "" || len(mediaItemIDs) == 0 {
|
|
return map[string]WatchProgress{}, nil
|
|
}
|
|
progressMap, err := store.ListProgressByMediaItems(ctx, profileID, mediaItemIDs)
|
|
if err != nil {
|
|
return nil, err
|
|
}
|
|
if progressMap == nil {
|
|
progressMap = map[string]WatchProgress{}
|
|
}
|
|
|
|
candidates := make([]string, 0, len(mediaItemIDs))
|
|
for _, mediaItemID := range mediaItemIDs {
|
|
if progress, ok := progressMap[mediaItemID]; ok && progress.Completed {
|
|
continue
|
|
}
|
|
candidates = append(candidates, mediaItemID)
|
|
}
|
|
if len(candidates) == 0 {
|
|
return progressMap, nil
|
|
}
|
|
|
|
completed := CompletedHistoryItemMap(ctx, store, CompletedHistoryItemQuery{
|
|
ProfileID: profileID,
|
|
MediaItemIDs: candidates,
|
|
})
|
|
for mediaItemID, completedItem := range completed {
|
|
if progress, ok := progressMap[mediaItemID]; ok {
|
|
progress.Completed = true
|
|
if timestampAfter(completedItem.WatchedAt, progress.UpdatedAt) {
|
|
progress.UpdatedAt = completedItem.WatchedAt
|
|
}
|
|
progressMap[mediaItemID] = progress
|
|
continue
|
|
}
|
|
progressMap[mediaItemID] = WatchProgress{
|
|
ProfileID: profileID,
|
|
MediaItemID: mediaItemID,
|
|
Completed: true,
|
|
UpdatedAt: completedItem.WatchedAt,
|
|
}
|
|
}
|
|
return progressMap, nil
|
|
}
|
|
|
|
func compactHistoryMediaItemIDs(mediaItemIDs []string) []string {
|
|
result := make([]string, 0, len(mediaItemIDs))
|
|
seen := make(map[string]struct{}, len(mediaItemIDs))
|
|
for _, mediaItemID := range mediaItemIDs {
|
|
mediaItemID = strings.TrimSpace(mediaItemID)
|
|
if mediaItemID == "" {
|
|
continue
|
|
}
|
|
if _, ok := seen[mediaItemID]; ok {
|
|
continue
|
|
}
|
|
seen[mediaItemID] = struct{}{}
|
|
result = append(result, mediaItemID)
|
|
}
|
|
return result
|
|
}
|
|
|
|
func timestampAfter(left, right string) bool {
|
|
if left == "" {
|
|
return false
|
|
}
|
|
if right == "" {
|
|
return true
|
|
}
|
|
leftTime, leftErr := time.Parse(time.RFC3339, left)
|
|
rightTime, rightErr := time.Parse(time.RFC3339, right)
|
|
if leftErr == nil && rightErr == nil {
|
|
return leftTime.After(rightTime)
|
|
}
|
|
return left > right
|
|
}
|