From d2ba65e383697d7ba629864772909d46fd118458 Mon Sep 17 00:00:00 2001 From: npeter83 Date: Fri, 11 Sep 2026 01:08:27 +0200 Subject: [PATCH] fix(plex): the subtitle poll backs off on errors, a failed is replaced, and a resume asks for the right window MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Deep-review R2, plus one defect found while verifying it on localdev. - The status poll re-armed every second after a FAILED request: `data` stays empty on an error, so it read as "still preparing" for as long as the player was open — and the request was not quiet, so a persistent 500 re-opened the global error dialog every second. It now backs off to 10 s (a blip still heals on its own) and is quiet; the player already shows the failure inline. - A whose own VTT fetch failed never fetched again: with the server's answer unchanged its key was unchanged, so React kept the dead element — silently blank subtitles. The key (now built in the hook, where it is tested) carries a failed-load count; after two remounts the track is reported as unavailable instead. - Found in UAT: until the first timeupdate `abs` is 0, so after a resume every poll said at=0 and the first window was cut around the head of the film (a resume at 20:00 polled at=0 for as long as it stayed paused). The poll reports the session's start until playback ticks. And the window's dedup identity is the track plus a window-length bucket of its start — keyed on the track alone (R1), the right window queued behind that wrong one. The poll's start/stop rules finally have tests (every earlier one resolved a single fixed answer). Verified on localdev against Westworld S1E6 resumed at 20:00: the polls carried at=1197, one subtitle line on screen at 21:02, the poll stopped at `ready`; the real file's window (56 cues) + full pass (608) merged to 608 — the old merge would have served 664. 11 mutations, all red. --- backend/app/plex/subtitles.py | 15 ++- backend/tests/test_plex_subtitle_prepare.py | 11 ++ frontend/src/components/PlexPlayer.tsx | 9 +- frontend/src/lib/api/plex.ts | 3 + .../lib/plexPlayerHooks.subtitle.dom.test.tsx | 113 +++++++++++++++++- frontend/src/lib/plexPlayerHooks.ts | 49 +++++++- 6 files changed, 179 insertions(+), 21 deletions(-) diff --git a/backend/app/plex/subtitles.py b/backend/app/plex/subtitles.py index 8c749c1c..f9048565 100644 --- a/backend/app/plex/subtitles.py +++ b/backend/app/plex/subtitles.py @@ -439,14 +439,17 @@ def _schedule(rating_key: str, sub_ord: int, at: float, want_window: bool) -> No full pass that makes it complete. Each is deduplicated by identity, so a 1 s status poll (or a second viewer) joins the running job instead of starting another ffmpeg. - A window's identity is its TRACK, never its position. The poll sends the live playhead, so a - position-keyed window minted a new identity every second and queued one more read of the file per - poll until the first window landed. One window per track is in flight at a time; a seek past it - is picked up by the next poll after it publishes. The full pass is per ITEM, because one read - fans out to every embedded text track of the file.""" + A window's identity is its track plus WHICH STRETCH of the film it is for — never the exact + position. The poll sends the live playhead, so a position-keyed window minted a new identity every + second and queued one more read of the file per poll until the first window landed; bucketing the + start by the window's own length makes a playhead creeping along join the job already running. It + must not be the track alone either: then a window cut around the wrong spot (the first poll after + a resume can still report 0) made the right one wait for it. The full pass is per ITEM, because + one read fans out to every embedded text track of the file.""" jobs: list[tuple[tuple, float | None]] = [] if want_window: - jobs.append((("win", rating_key, sub_ord), max(0.0, at - WINDOW_PRE_S))) + w_start = max(0.0, at - WINDOW_PRE_S) + jobs.append((("win", rating_key, sub_ord, int(w_start // WINDOW_LEN_S)), w_start)) jobs.append((("full", rating_key), None)) for ident, window_start in jobs: with _LOCK: diff --git a/backend/tests/test_plex_subtitle_prepare.py b/backend/tests/test_plex_subtitle_prepare.py index 633c2587..13c572b1 100644 --- a/backend/tests/test_plex_subtitle_prepare.py +++ b/backend/tests/test_plex_subtitle_prepare.py @@ -395,6 +395,17 @@ def test_polls_that_follow_the_playhead_join_one_window(monkeypatch): assert len(pool.jobs) == 2, "one window + the one full pass" +def test_a_window_for_a_different_stretch_does_not_wait_behind_the_first(monkeypatch): + """Measured on localdev: after a resume the first poll can still report 0 (the position is only + known once playback ticks), so the first window is cut around the wrong spot. The poll that + follows, at the real position, must get its own window at once — not queue behind that one.""" + pool = _ManualPool() + monkeypatch.setattr(subtitles, "_POOL", pool) + subtitles.ensure("98614", 1, at=0.0) + subtitles.ensure("98614", 1, at=1198.0) + assert sorted(a[3] for _, a in pool.jobs if a[3] is not None) == [0.0, 1168.0] + + def test_a_queued_window_that_was_covered_meanwhile_reads_nothing(monkeypatch): """Every embedded track rides each pass over its file, so by the time a queued window for one language runs, another language's window may already have published it.""" diff --git a/frontend/src/components/PlexPlayer.tsx b/frontend/src/components/PlexPlayer.tsx index 43c7a747..e7f3242d 100644 --- a/frontend/src/components/PlexPlayer.tsx +++ b/frontend/src/components/PlexPlayer.tsx @@ -380,6 +380,7 @@ export default function PlexPlayer({ itemId, onClose, queue }: Props) { subShowable, subFail, subGen, + subTrackKey, onSubTrackError, } = usePlexTracks({ id, @@ -873,10 +874,10 @@ export default function PlexPlayer({ itemId, onClose, queue }: Props) { above flips modes; the browser fetches a track's VTT the first time it's shown. */} {selectedSub && subShowable && ( => + // `quiet`: the player reports a failed poll inline, so no global error dialog on top of it. req( `/api/plex/subtitle/${encodeURIComponent(id)}/${ord}/status?at=${Math.max(0, Math.floor(at))}`, + undefined, + { quiet: true }, ), // `final` marks a settled checkpoint (pause / page-hide / leaving the player) as opposed to the // periodic 10s tick — the backend mirrors the resume position to a linked Plex account only on a diff --git a/frontend/src/lib/plexPlayerHooks.subtitle.dom.test.tsx b/frontend/src/lib/plexPlayerHooks.subtitle.dom.test.tsx index 6dc61625..3bb046da 100644 --- a/frontend/src/lib/plexPlayerHooks.subtitle.dom.test.tsx +++ b/frontend/src/lib/plexPlayerHooks.subtitle.dom.test.tsx @@ -9,12 +9,13 @@ // until the cache happened to be warm. The extraction now runs in the background, publishing a // window around the playhead first, and this hook's poll is what decides when there is something to // mount and what to say while there isn't. -import { describe, it, expect, vi, afterEach } from "vitest"; -import { cleanup, renderHook, waitFor } from "@testing-library/react"; +import { describe, it, expect, vi, afterEach, beforeEach } from "vitest"; +import { act, cleanup, renderHook, waitFor } from "@testing-library/react"; import { QueryClient, QueryClientProvider } from "@tanstack/react-query"; import { createRef, type ReactNode, type MutableRefObject } from "react"; import { usePlexTracks } from "./plexPlayerHooks"; import { api, type PlexItemDetail } from "./api"; +import { dismissError, getError } from "./errorDialog"; import type Hls from "hls.js"; const RK = "98614"; @@ -31,7 +32,7 @@ const detail = (): PlexItemDetail => markers: [], }) as unknown as PlexItemDetail; -function mount(qc: QueryClient) { +function mount(qc: QueryClient, { sessionK = 0, abs = 3600 } = {}) { const wrapper = ({ children }: { children: ReactNode }) => ( {children} ); @@ -40,7 +41,7 @@ function mount(qc: QueryClient) { usePlexTracks({ id: RK, detail: detail(), - sessionK: 0, + sessionK, subOffset: 0, subPos: 88, loadSession: async () => {}, @@ -50,7 +51,7 @@ function mount(qc: QueryClient) { multiAudioRef: { current: false }, audioRef: { current: 0 } as MutableRefObject, aoffRef: { current: 0 }, - absRef: { current: 3600 }, + absRef: { current: abs }, }), { wrapper }, ); @@ -91,6 +92,18 @@ describe("usePlexTracks — the waits for the extraction", () => { await waitFor(() => expect(status).toHaveBeenCalledWith(RK, 1, 3600)); }); + it("sends the session's start before playback has ticked, not the head of the film", async () => { + // A resumed session starts minutes in, but `abs` stays 0 until the first timeupdate — and every + // poll used to say at=0, so the first window was cut around the head of the film (measured on + // localdev: a resume at 20:00 polled at=0 for as long as it stayed paused). + const status = vi + .spyOn(api, "plexSubtitleStatus") + .mockResolvedValue({ state: "preparing", code: null, gen: 0 }); + const { result } = mount(client(), { sessionK: 1198, abs: 0 }); + result.current.setSubOrd(1); + await waitFor(() => expect(status).toHaveBeenCalledWith(RK, 1, 1198)); + }); + it("becomes showable on a PARTIAL track — a window around the playhead is what is needed now", async () => { vi.spyOn(api, "plexSubtitleStatus").mockResolvedValue({ state: "partial", @@ -138,3 +151,93 @@ describe("usePlexTracks — the waits for the extraction", () => { expect(result.current.subShowable).toBe(false); }); }); + +// The poll's refetch rules ARE the feature: nothing else turns "preparing" into subtitles on screen, +// and nothing else stops a settled track from being asked about for the length of the film. Every +// test above resolves one fixed answer, so none of them ever reached the refetch callback. +describe("usePlexTracks — when the status poll asks again, and when it stops", () => { + beforeEach(() => { + vi.useFakeTimers({ shouldAdvanceTime: true }); + }); + afterEach(() => { + cleanup(); + vi.useRealTimers(); + vi.restoreAllMocks(); + }); + + it("keeps asking until a window lands, then shows it without the viewer doing anything", async () => { + const status = vi + .spyOn(api, "plexSubtitleStatus") + .mockResolvedValueOnce({ state: "preparing", code: null, gen: 0 }) + .mockResolvedValue({ state: "partial", code: null, gen: 7 }); + const { result } = mount(client()); + result.current.setSubOrd(0); + await waitFor(() => expect(status).toHaveBeenCalledTimes(1)); + expect(result.current.subShowable).toBe(false); + await vi.advanceTimersByTimeAsync(1100); + await waitFor(() => expect(result.current.subShowable).toBe(true)); + }); + + it.each([ + ["the whole track is there", { state: "ready" as const, code: null, gen: 3 }], + ["it can never be shown", { state: "failed" as const, code: "bitmap", gen: 0 }], + ])("stops asking once the answer is settled — %s", async (_, answer) => { + const status = vi.spyOn(api, "plexSubtitleStatus").mockResolvedValue(answer); + const { result } = mount(client()); + result.current.setSubOrd(0); + await waitFor(() => expect(status).toHaveBeenCalledTimes(1)); + await vi.advanceTimersByTimeAsync(5000); + expect(status).toHaveBeenCalledTimes(1); + }); + + it("backs off after a failed request, and still asks again so a blip heals on its own", async () => { + // A failed request leaves `data` empty; it used to read as "still preparing" and re-ask every + // second for as long as the player stayed open. + const status = vi.spyOn(api, "plexSubtitleStatus").mockRejectedValue(new Error("offline")); + const { result } = mount(client()); + result.current.setSubOrd(0); + await waitFor(() => expect(result.current.subFail).toBe("failed")); + expect(status).toHaveBeenCalledTimes(1); + await vi.advanceTimersByTimeAsync(5000); + expect(status).toHaveBeenCalledTimes(1); + await vi.advanceTimersByTimeAsync(6000); + expect(status).toHaveBeenCalledTimes(2); + }); + + it("does not raise the global error dialog when it fails — the player says so inline", async () => { + dismissError(); + vi.spyOn(globalThis, "fetch").mockResolvedValue( + new Response(JSON.stringify({ detail: "boom" }), { + status: 500, + headers: { "content-type": "application/json" }, + }), + ); + await expect(api.plexSubtitleStatus(RK, 0, 0)).rejects.toThrow(); + expect(getError()).toBeNull(); + }); +}); + +describe("usePlexTracks — a whose own VTT fetch failed", () => { + afterEach(() => { + cleanup(); + vi.restoreAllMocks(); + }); + + it("is replaced by a fresh element a couple of times, then reported instead of left blank", async () => { + // A failed never fetches again, and while the server's answer is unchanged its key was + // unchanged too — so React kept the dead element and the subtitles stayed silently blank. + vi.spyOn(api, "plexSubtitleStatus").mockResolvedValue({ state: "partial", code: null, gen: 5 }); + const { result } = mount(client()); + result.current.setSubOrd(0); + await waitFor(() => expect(result.current.subShowable).toBe(true)); + for (let i = 0; i < 2; i++) { + const before = result.current.subTrackKey; + act(() => result.current.onSubTrackError()); + await waitFor(() => expect(result.current.subTrackKey).not.toBe(before)); + expect(result.current.subShowable).toBe(true); + } + act(() => result.current.onSubTrackError()); + await waitFor(() => expect(result.current.subShowable).toBe(false)); + expect(result.current.subFail).toBe("failed"); + }); +}); diff --git a/frontend/src/lib/plexPlayerHooks.ts b/frontend/src/lib/plexPlayerHooks.ts index e6700d43..4ccadaa6 100644 --- a/frontend/src/lib/plexPlayerHooks.ts +++ b/frontend/src/lib/plexPlayerHooks.ts @@ -349,6 +349,11 @@ export function useAutoSkip(opts: { * fold happens here rather than multiplying near-identical translations. */ export type SubFailReason = "bitmap" | "missing" | "failed"; +// The subtitle status poll's cadence after a FAILED request (see usePlexTracks), and how many times a +// whose own VTT fetch failed is remounted before the track is reported as unavailable. +const SUB_POLL_ERROR_MS = 10_000; +const SUB_TRACK_RETRIES = 2; + function subFailReason(code: string | null | undefined): SubFailReason { if (code === "bitmap") return "bitmap"; if (code === "no_item" || code === "no_track" || code === "no_file" || code === "not_fetchable") @@ -394,6 +399,11 @@ export function usePlexTracks(opts: { /** The cached VTT's generation — it grows as the background extraction widens the track, so it * belongs in the key/URL or the browser keeps serving the first, short window. */ subGen: number; + /** The 's React key. Everything that must produce a FRESH element — and so a fresh VTT + * fetch — is in it: the item and track, the shifted offset (a seek-restart or a debounced offset + * change), the extraction generation (a widened track replaces the first short window), and the + * failed-load count (a whose fetch failed is replaced rather than left dead). */ + subTrackKey: string; onSubTrackError: () => void; } { const { id, detail, sessionK, subOffset, subPos, loadSession, patchPrefs } = opts; @@ -486,14 +496,28 @@ export function usePlexTracks(opts: { // around the playhead first, and this poll is what tells us when there is something to mount. const subStatusQ = useQuery({ queryKey: qk.plexSubtitle(id, subOrd ?? -1), - queryFn: () => api.plexSubtitleStatus(id, subOrd as number, absRef.current ?? 0), + // The position is only known once playback has ticked: until the first timeupdate `abs` is 0 + // even though a resumed session starts minutes in — and every poll said `at=0`, so the first + // window was cut around the head of the film instead of where the viewer is (measured on + // localdev: a resume at 20:00 polled `at=0` for as long as it stayed paused). The session's own + // start is the best answer until then. + queryFn: () => + api.plexSubtitleStatus(id, subOrd as number, absRef.current > 0 ? absRef.current : sessionK), enabled: subOrd != null, // Keep polling until the track is COMPLETE, not just showable: each poll carries the current // position, so seeking past the extracted window is what asks for the next one. A settled // answer — the whole track, or a reason it can never be shown — stops the poll; without that // stop, a bitmap track would poll for the length of the film AND keep re-arming the extraction // every time the server's short failure memo expired. + // + // A FAILED request is neither: it says nothing about the track. It must not keep the 1 s cadence + // (it used to — `data` stays empty on an error, so every failure read as "still preparing" and + // re-armed a second later, for as long as the player was open), but it must not end the poll + // either, or one dropped request would leave "unavailable" on screen for a track that is fine. + // So it backs off to SUB_POLL_ERROR_MS; the player shows the failure inline meanwhile, which is + // also why the request is `quiet` (no global error dialog re-opening under the film). refetchInterval: (q) => { + if (q.state.status === "error") return SUB_POLL_ERROR_MS; const st = q.state.data?.state; if (st === "ready" || st === "failed") return false; return st === "partial" ? 2000 : 1000; @@ -502,20 +526,32 @@ export function usePlexTracks(opts: { retry: false, }); const subStatus = subOrd == null ? null : (subStatusQ.data ?? null); + // A whose own VTT fetch failed never fetches again, and re-asking the status cannot fix + // that on its own: while the answer (and its `gen`) is unchanged the key is unchanged, so React + // keeps the dead element and the subtitles stay silently blank. So a failed load bumps a counter + // that is part of the key — a fresh element, a fresh fetch — and after SUB_TRACK_RETRIES the track + // is reported as unavailable instead of left blank. The count belongs to one track generation: a + // different track, item or `gen` starts from zero. + const loadKey = `${id}:${subOrd}:${subStatus?.gen ?? 0}`; + const [loadFails, setLoadFails] = useState({ key: "", n: 0 }); + const subRetry = loadFails.key === loadKey ? loadFails.n : 0; + const subGaveUp = subRetry > SUB_TRACK_RETRIES; // Mount the for a `partial` track too: a window around the playhead is exactly what the // viewer needs right now, and the poll widens it underneath them. - const subShowable = subStatus?.state === "ready" || subStatus?.state === "partial"; + const subShowable = + (subStatus?.state === "ready" || subStatus?.state === "partial") && !subGaveUp; const subFail: SubFailReason | null = - subStatusQ.isError && subOrd != null + (subStatusQ.isError || subGaveUp) && subOrd != null ? "failed" : subStatus?.state === "failed" ? subFailReason(subStatus.code) : null; - // A that errors anyway (the cached VTT was evicted between the poll and the fetch) goes - // back to polling rather than staying silently blank. const onSubTrackError = useCallback(() => { + setLoadFails((f) => ({ key: loadKey, n: (f.key === loadKey ? f.n : 0) + 1 })); + // …and ask again: if the cached VTT was evicted between the poll and the fetch, the answer drops + // back to `preparing` and the poll takes over until it has been re-extracted. if (subOrd != null) qc.invalidateQueries({ queryKey: qk.plexSubtitle(id, subOrd) }); - }, [qc, id, subOrd]); + }, [qc, id, subOrd, loadKey]); // Text subtitles offered in the picker; image subs (PGS/VobSub) can't be shown as text. const textSubs = (detail?.subtitle_streams ?? []).filter((s) => s.text); @@ -586,6 +622,7 @@ export function usePlexTracks(opts: { subShowable, subFail, subGen: subStatus?.gen ?? 0, + subTrackKey: `${id}-${subOrd}-${subTrackOffset.toFixed(2)}-${subStatus?.gen ?? 0}-${subRetry}`, onSubTrackError, }; }