From c60359bfedfa7d00e2a027a89fe5db8bc0717326 Mon Sep 17 00:00:00 2001 From: npeter83 Date: Sat, 19 Sep 2026 07:07:53 +0200 Subject: [PATCH] =?UTF-8?q?fix(plex):=20subtitles=20=E2=80=94=20a=20retrie?= =?UTF-8?q?d=20full=20pass=20resumes,=20a=20stalled=20track=20is=20polled?= =?UTF-8?q?=20slowly?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit A full pass that ran out of time kept what it reached, but its retry an hour later started again at 0, so a file too big to read inside the extraction timeout never completed. The pass now starts where every embedded track's coverage from the head ends (less the window pre-roll, so a cue across the join is read whole). The seek needs -avoid_negative_ts on this read as on a window, measured on a real file: without it the cue running at the start shifts the whole output. A partial track whose full pass had failed never reached a settled state, so the player polled it every 2 s for the rest of the film. The status now says whether the track is still growing, and a stalled one is polled every 15 s — still inside the 60 s lookahead that reads the next window before an edge. --- backend/app/plex/subtitles.py | 38 +++++++++-- backend/tests/test_plex_subtitle_prepare.py | 67 +++++++++++++++++++ frontend/src/lib/api/plex.ts | 2 + .../lib/plexPlayerHooks.subtitle.dom.test.tsx | 16 +++++ frontend/src/lib/plexPlayerHooks.ts | 8 ++- 5 files changed, 126 insertions(+), 5 deletions(-) diff --git a/backend/app/plex/subtitles.py b/backend/app/plex/subtitles.py index c09e97ec..67f62cd2 100644 --- a/backend/app/plex/subtitles.py +++ b/backend/app/plex/subtitles.py @@ -642,7 +642,15 @@ def ensure(rating_key: str, sub_ord: int, at: float = 0.0) -> dict: probe = edge + 1.0 want_window = not _window_failed(key, probe) _schedule(rating_key, sub_ord, probe, want_window=want_window, want_full=not full_failed) - return {"state": "partial" if covered else "preparing", "code": None, "gen": gen} + # `growing`: whether the track will fill in on its own. False once the full pass has failed and + # is backed off — a partial track then stays partial until a window is asked for, so the player + # may poll slowly (only to read ahead of an edge) instead of every two seconds for the whole film. + return { + "state": "partial" if covered else "preparing", + "code": None, + "gen": gen, + "growing": not full_failed, + } def cached_track(rating_key: str, sub_ord: int) -> tuple[str | None, str | None]: @@ -822,10 +830,13 @@ def _extract_and_publish(rating_key: str, sub_ord: int, window_start: float | No for i, s in enumerate(subs) if s.get("index") is not None and not _is_bitmap(s) } - start = window_start or 0.0 + # A full pass starts where every track's leading coverage ends: a pass that ran out of time + # (`EXTRACT_TIMEOUT_S`) kept what it reached, and restarting from 0 each `FULL_RETRY_S` meant a file + # too big to read in one go never completed. Windows handle an offset start already; so does this. + start = window_start if window_start is not None else _full_pass_start(rating_key, targets) length = (WINDOW_LEN_S + WINDOW_PRE_S) if window_start is not None else None end = _FULL_END_S if length is None else start + length - texts, clean = _ffmpeg_extract(str(src), sorted(targets), window_start, length) + texts, clean = _ffmpeg_extract(str(src), sorted(targets), start or None, length) for emb_ord, vtt in texts.items(): key = cache_key(rating_key, targets[emb_ord]) # A pass that exited non-zero holds only what ffmpeg reached before it died. Claim no more @@ -846,6 +857,24 @@ def _extract_and_publish(rating_key: str, sub_ord: int, window_start: float | No _pass_failed(rating_key, [key], window_start, (covered_end, end)) +def _full_pass_start(rating_key: str, targets: dict[int, int]) -> float: + """Where the full pass may begin: the end of the span from 0 that EVERY target track already has + (one read feeds them all, so the least-covered track decides), backed off by `WINDOW_PRE_S` so a + cue running across the join is read whole — `merge_vtt` folds the overlap. 0 when any track has + nothing from the start.""" + ends = [] + for ord_ in targets.values(): + key = cache_key(rating_key, ord_) + ranges, _ = read_meta(key) if _exists(_vtt_path(key)) else ([], False) + lead = [b for a, b in ranges if a <= 0.0] + if not lead: + return 0.0 + ends.append(max(lead)) + if not ends: + return 0.0 + return max(0.0, float(f"{min(ends) - WINDOW_PRE_S:.3f}")) + + def _sidecar_vtt(db: Session, stream: dict) -> str: """An external subtitle file, fetched through Plex and converted to WebVTT.""" with PlexClient(db) as plex: @@ -884,9 +913,10 @@ def _ffmpeg_extract( cmd += ["-map", f"0:s:{emb_ord}"] if length is not None: cmd += ["-t", f"{length:.3f}"] + if start: # The input seek lands on the keyframe at or BEFORE `start`, so a cue already running # at `start` comes out at a negative time — and by default the muxer then shifts the - # WHOLE output so that cue sits at 0: every cue of the window late by the distance to + # WHOLE output so that cue sits at 0: every cue of the read late by the distance to # that keyframe (1–5 s measured on a real library file, a whole GOP on a synthetic # one), and doubled for good once the full pass merged in beside it. Kept negative, the # times are exact on the zero-based clock (`_vtt_ts_to_s` reads the sign). diff --git a/backend/tests/test_plex_subtitle_prepare.py b/backend/tests/test_plex_subtitle_prepare.py index fcaa4aa0..9a0dbcc8 100644 --- a/backend/tests/test_plex_subtitle_prepare.py +++ b/backend/tests/test_plex_subtitle_prepare.py @@ -412,6 +412,54 @@ def test_a_full_pass_that_died_is_not_cached_as_the_whole_track(monkeypatch): assert (after["state"], after["code"]) == ("unavailable", "extract_failed") +def test_a_retried_full_pass_resumes_where_every_track_already_reaches(monkeypatch): + """A pass that ran out of time keeps what it reached, but the retry an hour later started again + at 0 — so a file too big to read inside `EXTRACT_TIMEOUT_S` never completed. It now starts at + the end of the span every track has from the start (less `WINDOW_PRE_S`, so a cue across the + join is read whole), and finishing from there completes the track.""" + calls = _stub_item(monkeypatch, clean=False, cues=("39:58.000", "40:00.000")) + _manual_pool(monkeypatch) + subtitles._extract_and_publish("98614", 3, None) + assert calls[-1] == ([0, 2], None, None), "the first pass reads from the head" + calls = _stub_item(monkeypatch, clean=True, cues=("00:05.000", "00:07.000")) + subtitles._extract_and_publish("98614", 3, None) + assert calls == [([0, 2], 2370.0, None)] + for sub_ord in (1, 3): + assert subtitles.read_meta(subtitles.cache_key("98614", sub_ord))[1] is True + assert "00:39:35.000 --> 00:39:37.000" in ( + subtitles.cache_read(subtitles.cache_key("98614", 3)) or "" + ), "the resumed read's cues sit at absolute time (2370 + 5 s)" + + +def test_a_full_pass_starts_at_the_head_while_any_track_lacks_it(monkeypatch): + """One read feeds every embedded track, so the least-covered one decides: a window elsewhere in + the film, or one track with the head and another without, still means reading from 0.""" + calls = _stub_item(monkeypatch) + _manual_pool(monkeypatch) + subtitles._extract_and_publish("98614", 3, 3570.0) # a window mid-film, both tracks + subtitles.publish(subtitles.cache_key("98614", 1), _vtt(), (0.0, 600.0), False) + subtitles._extract_and_publish("98614", 3, None) + assert calls[-1] == ([0, 2], None, None) + + +def test_the_status_says_whether_the_track_is_still_growing(monkeypatch): + """`partial` alone kept the player polling every 2 s for the rest of the film once the full + pass had failed and backed off — a state that never reaches `ready` on its own.""" + _stub_item(monkeypatch, clean=True, cues=("00:05.000", "00:07.000")) + pool = _manual_pool(monkeypatch) + subtitles._extract_and_publish("98614", 3, 0.0) + assert subtitles.ensure("98614", 3, at=10.0)["growing"] is True + pool.jobs.clear() + _stub_item(monkeypatch, clean=False, cues=("39:58.000", "40:00.000")) + subtitles._extract_and_publish("98614", 3, None) + assert subtitles.ensure("98614", 3, at=100.0) == { + "state": "partial", + "code": None, + "gen": subtitles.generation(subtitles.cache_key("98614", 3)), + "growing": False, + } + + def test_polls_that_follow_the_playhead_join_one_window(monkeypatch): """The poll sends the LIVE position, so it moves a second per poll. A window keyed on that position was a new job every second — another read of the file per poll until the first landed.""" @@ -797,6 +845,25 @@ def test_a_window_lines_up_with_the_full_pass_on_a_real_file(tmp_path, monkeypat assert merged.count("-->") == 30, "a window cue survived beside its full-pass twin" +@needs_ffmpeg +def test_a_full_pass_resumed_mid_file_lines_up_on_a_real_file(tmp_path, monkeypatch): + """A retried full pass seeks like a window does but reads to the end (no `-t`): the cue already + running at its start must come out on time, not shifted to 0 with everything after it.""" + src = _make_mkv(tmp_path) + monkeypatch.setattr(subtitles, "CACHE_DIR", tmp_path / "cache") + head, clean = subtitles._ffmpeg_extract(str(src), [0], None, 30.0) + assert clean + rest, clean = subtitles._ffmpeg_extract(str(src), [0], 21.3, None) + assert clean + key = subtitles.cache_key("1", 0) + subtitles.publish(key, head[0], (0.0, 30.0), False) + subtitles.publish(key, subtitles.shift_vtt(rest[0], -21.3), (21.3, subtitles._FULL_END_S), True) + merged = subtitles.cache_read(key) or "" + assert "00:00:22.000 --> 00:00:23.500\nline 11" in merged, merged + assert "00:00:58.000 --> 00:00:59.500\nline 29" in merged, merged + assert merged.count("-->") == 30, "a cue across the join was kept twice or lost" + + # --- the third deep-review round ---------------------------------------------------------------- diff --git a/frontend/src/lib/api/plex.ts b/frontend/src/lib/api/plex.ts index 5042a861..f9d1be7c 100644 --- a/frontend/src/lib/api/plex.ts +++ b/frontend/src/lib/api/plex.ts @@ -678,6 +678,8 @@ export const plexApi = { state: "ready" | "partial" | "preparing" | "unavailable" | "failed"; code: string | null; gen: number; + /** On `partial`/`preparing`: whether the track still fills in on its own. */ + growing?: boolean; }> => // `quiet`: the player reports a failed poll inline, so no global error dialog on top of it. req( diff --git a/frontend/src/lib/plexPlayerHooks.subtitle.dom.test.tsx b/frontend/src/lib/plexPlayerHooks.subtitle.dom.test.tsx index a1ebf86c..a56c0cdf 100644 --- a/frontend/src/lib/plexPlayerHooks.subtitle.dom.test.tsx +++ b/frontend/src/lib/plexPlayerHooks.subtitle.dom.test.tsx @@ -208,6 +208,22 @@ describe("usePlexTracks — when the status poll asks again, and when it stops", expect(status).toHaveBeenCalledTimes(1); }); + it("slows down on a partial track that will not grow on its own, and keeps asking", async () => { + // The full pass failed and is backed off for an hour: `partial` never turns `ready` by itself, + // and the 2 s cadence ran for the rest of the film. It still carries the position — reading + // ahead of an edge depends on it — so it slows rather than stops. + const status = vi + .spyOn(api, "plexSubtitleStatus") + .mockResolvedValue({ state: "partial", code: null, gen: 4, growing: false }); + const { result } = mount(client()); + result.current.setSubOrd(0); + await waitFor(() => expect(status).toHaveBeenCalledTimes(1)); + await vi.advanceTimersByTimeAsync(10_000); + expect(status).toHaveBeenCalledTimes(1); + await vi.advanceTimersByTimeAsync(6000); + expect(status).toHaveBeenCalledTimes(2); + }); + 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. diff --git a/frontend/src/lib/plexPlayerHooks.ts b/frontend/src/lib/plexPlayerHooks.ts index 82f002f7..6ca2e3fd 100644 --- a/frontend/src/lib/plexPlayerHooks.ts +++ b/frontend/src/lib/plexPlayerHooks.ts @@ -484,6 +484,11 @@ const SUB_POLL_ERROR_MS = 10_000; // server keeps for a minute), so no need for the 1 s cadence — but the poll carries the position, and // moving into a stretch that IS cached should stop saying "couldn't be loaded" within a few seconds. const SUB_POLL_UNAVAILABLE_MS = 5_000; +// …and on a `partial` track that is no longer `growing` (its full pass failed and is backed off for +// an hour): it will not fill in on its own, so the 2 s cadence ran for the rest of the film. The poll +// still carries the position — it is what reads the next window ahead of an edge, which the server +// starts within LOOKAHEAD_S (60 s) of it — so it slows down rather than stops. +const SUB_POLL_STALLED_MS = 15_000; const SUB_TRACK_RETRIES = 2; const SUB_TRACK_RETRY_MS = 2_000; @@ -684,7 +689,8 @@ export function usePlexTracks(opts: { const st = q.state.data?.state; if (st === "ready" || st === "failed") return false; if (st === "unavailable") return SUB_POLL_UNAVAILABLE_MS; - return st === "partial" ? 2000 : 1000; + if (st === "partial") return q.state.data?.growing === false ? SUB_POLL_STALLED_MS : 2000; + return 1000; }, staleTime: 0, retry: false,