fix(downloads): R5 S1 — downloads robustness
- pick the produced file safely: Path("") is Path("."), which passes .exists(),
so a missing yt-dlp filepath skipped the staging fallback and crashed in
with_name ("PosixPath('.') has an empty name") on non-YouTube sources
- unwrap a playlist/multi_video extraction to the entry that carries the media
- run_ffmpeg: drain stderr while it runs (a full 64KB pipe blocked ffmpeg
forever and hung the worker thread), 1s cancel polling, stall watchdog and a
bounded wait on exit
- escape apostrophes/backslashes in the ffmpeg concat list (pre-0.51.0 names)
- sweep orphaned HLS segment dirs at startup (nothing else ever reaped them)
This commit is contained in:
+105
-19
@@ -24,7 +24,10 @@ import hashlib
|
|||||||
import json
|
import json
|
||||||
import logging
|
import logging
|
||||||
import math
|
import math
|
||||||
|
import queue
|
||||||
import subprocess
|
import subprocess
|
||||||
|
import threading
|
||||||
|
import time
|
||||||
from pathlib import Path
|
from pathlib import Path
|
||||||
|
|
||||||
log = logging.getLogger("siftlode.edit")
|
log = logging.getLogger("siftlode.edit")
|
||||||
@@ -178,6 +181,16 @@ def build_edit_cmd(src: Path, dest: Path, spec: dict, out_ext: str) -> list[str]
|
|||||||
return cmd
|
return cmd
|
||||||
|
|
||||||
|
|
||||||
|
def _concat_quote(path: Path) -> str:
|
||||||
|
"""Escape a path for a single-quoted `file '…'` line of an ffmpeg concat list.
|
||||||
|
|
||||||
|
The demuxer's own rule: inside single quotes a literal `'` is written `'\\''` (close, escaped
|
||||||
|
quote, reopen) and a `\\` must be doubled. On-disk names have been ASCII-slugged since 0.51.0,
|
||||||
|
but that change is FORWARD-ONLY — a pre-0.51.0 file still on disk can be named `Don't_….mp4`,
|
||||||
|
and an unescaped apostrophe there makes the whole list unparseable."""
|
||||||
|
return path.as_posix().replace("\\", "\\\\").replace("'", "'\\''")
|
||||||
|
|
||||||
|
|
||||||
def build_concat_plan(src: Path, dest: Path, spec: dict, out_ext: str, staging: Path):
|
def build_concat_plan(src: Path, dest: Path, spec: dict, out_ext: str, staging: Path):
|
||||||
"""Plan a multi-segment JOIN (cut-list → one file). Returns (cmd, prep_files) where prep_files
|
"""Plan a multi-segment JOIN (cut-list → one file). Returns (cmd, prep_files) where prep_files
|
||||||
maps a path → text content the worker must write before running (a concat list, if any).
|
maps a path → text content the worker must write before running (a concat list, if any).
|
||||||
@@ -211,7 +224,7 @@ def build_concat_plan(src: Path, dest: Path, spec: dict, out_ext: str, staging:
|
|||||||
listp = staging / "concat.txt"
|
listp = staging / "concat.txt"
|
||||||
lines = []
|
lines = []
|
||||||
for s in segs:
|
for s in segs:
|
||||||
lines.append(f"file '{src.as_posix()}'")
|
lines.append(f"file '{_concat_quote(src)}'")
|
||||||
lines.append(f"inpoint {s['start_s']}")
|
lines.append(f"inpoint {s['start_s']}")
|
||||||
lines.append(f"outpoint {s['end_s']}")
|
lines.append(f"outpoint {s['end_s']}")
|
||||||
prep[listp] = "\n".join(lines) + "\n"
|
prep[listp] = "\n".join(lines) + "\n"
|
||||||
@@ -238,34 +251,107 @@ def _parse_out_time(line: str) -> float | None:
|
|||||||
return None
|
return None
|
||||||
|
|
||||||
|
|
||||||
def run_ffmpeg(cmd, total_s, on_progress, should_cancel) -> None:
|
# No output on `-progress pipe:1` for this long means ffmpeg is wedged (a stuck network source, a
|
||||||
|
# hung filter) — a download job may legitimately be slow, but it is never SILENT for minutes.
|
||||||
|
_FFMPEG_STALL_TIMEOUT_S = 600.0
|
||||||
|
# Hard cap after we ask the process to go away; past it we stop waiting on it altogether.
|
||||||
|
_FFMPEG_EXIT_GRACE_S = 10.0
|
||||||
|
|
||||||
|
|
||||||
|
def _pump(stream, sink: "queue.Queue[str | None]") -> None:
|
||||||
|
"""Read a text pipe to EOF into a queue (None = EOF). Runs in its own thread so the main loop
|
||||||
|
can time out and poll cancel instead of blocking forever on a silent ffmpeg."""
|
||||||
|
try:
|
||||||
|
for line in stream:
|
||||||
|
sink.put(line)
|
||||||
|
except (ValueError, OSError): # pipe closed under us by the kill path
|
||||||
|
pass
|
||||||
|
finally:
|
||||||
|
sink.put(None)
|
||||||
|
|
||||||
|
|
||||||
|
def _drain_tail(stream, sink: list[str]) -> None:
|
||||||
|
"""Consume a pipe to EOF, keeping only its tail.
|
||||||
|
|
||||||
|
ffmpeg's stderr MUST be read *while it runs*: the OS pipe buffer is ~64KB, and once it fills,
|
||||||
|
ffmpeg blocks forever on its next write — the process never exits, so `proc.wait()` never
|
||||||
|
returns and the worker thread is gone for good. Reading it only after the exit (as this used
|
||||||
|
to) is exactly the deadlock."""
|
||||||
|
try:
|
||||||
|
for line in stream:
|
||||||
|
sink.append(line)
|
||||||
|
if len(sink) > 200:
|
||||||
|
del sink[:100]
|
||||||
|
except (ValueError, OSError):
|
||||||
|
pass
|
||||||
|
|
||||||
|
|
||||||
|
def _stop(proc: subprocess.Popen) -> None:
|
||||||
|
"""Terminate, then kill — never wait unbounded on a process we've given up on."""
|
||||||
|
proc.terminate()
|
||||||
|
try:
|
||||||
|
proc.wait(timeout=5)
|
||||||
|
except subprocess.TimeoutExpired:
|
||||||
|
proc.kill()
|
||||||
|
try:
|
||||||
|
proc.wait(timeout=5)
|
||||||
|
except subprocess.TimeoutExpired:
|
||||||
|
log.error("ffmpeg pid %s survived SIGKILL", proc.pid)
|
||||||
|
|
||||||
|
|
||||||
|
def run_ffmpeg(cmd, total_s, on_progress, should_cancel, stall_timeout_s=_FFMPEG_STALL_TIMEOUT_S) -> None:
|
||||||
"""Run an ffmpeg edit, reporting 0–100 progress and honouring cooperative cancel.
|
"""Run an ffmpeg edit, reporting 0–100 progress and honouring cooperative cancel.
|
||||||
|
|
||||||
Raises EditAborted if should_cancel() turns True mid-run, RuntimeError on a nonzero exit."""
|
Both pipes are drained by threads (see `_drain_tail`) and the main loop polls on a 1s tick, so
|
||||||
|
cancel is honoured within a second even while ffmpeg is quiet, and a wedged process is killed
|
||||||
|
by the stall watchdog instead of pinning a worker thread forever.
|
||||||
|
|
||||||
|
Raises EditAborted if should_cancel() turns True mid-run, RuntimeError on a nonzero exit or a
|
||||||
|
stall."""
|
||||||
proc = subprocess.Popen(
|
proc = subprocess.Popen(
|
||||||
cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, text=True, bufsize=1
|
cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, text=True, bufsize=1
|
||||||
)
|
)
|
||||||
|
err_tail: list[str] = []
|
||||||
|
lines: queue.Queue[str | None] = queue.Queue()
|
||||||
|
readers = [
|
||||||
|
threading.Thread(target=_pump, args=(proc.stdout, lines), daemon=True),
|
||||||
|
threading.Thread(target=_drain_tail, args=(proc.stderr, err_tail), daemon=True),
|
||||||
|
]
|
||||||
|
for t in readers:
|
||||||
|
t.start()
|
||||||
try:
|
try:
|
||||||
assert proc.stdout is not None
|
last_output = time.monotonic()
|
||||||
for line in proc.stdout:
|
while True:
|
||||||
line = line.strip()
|
try:
|
||||||
|
line = lines.get(timeout=1.0)
|
||||||
|
except queue.Empty:
|
||||||
|
line = ""
|
||||||
|
if line is None: # stdout hit EOF — ffmpeg is done (or dying)
|
||||||
|
break
|
||||||
|
if line:
|
||||||
|
last_output = time.monotonic()
|
||||||
|
secs = _parse_out_time(line.strip())
|
||||||
|
if secs is not None and total_s:
|
||||||
|
on_progress(max(0.0, min(99.0, secs * 100.0 / total_s)))
|
||||||
if should_cancel():
|
if should_cancel():
|
||||||
proc.terminate()
|
_stop(proc)
|
||||||
try:
|
|
||||||
proc.wait(timeout=5)
|
|
||||||
except subprocess.TimeoutExpired:
|
|
||||||
proc.kill()
|
|
||||||
raise EditAborted
|
raise EditAborted
|
||||||
secs = _parse_out_time(line)
|
if time.monotonic() - last_output > stall_timeout_s:
|
||||||
if secs is not None and total_s:
|
_stop(proc)
|
||||||
on_progress(max(0.0, min(99.0, secs * 100.0 / total_s)))
|
raise RuntimeError(f"ffmpeg stalled: no progress for {int(stall_timeout_s)}s")
|
||||||
|
try:
|
||||||
|
ret = proc.wait(timeout=_FFMPEG_EXIT_GRACE_S)
|
||||||
|
except subprocess.TimeoutExpired: # pipes closed but the process lingers
|
||||||
|
_stop(proc)
|
||||||
|
raise RuntimeError("ffmpeg did not exit after closing its output")
|
||||||
finally:
|
finally:
|
||||||
if proc.stdout:
|
for t in readers:
|
||||||
proc.stdout.close()
|
t.join(timeout=_FFMPEG_EXIT_GRACE_S)
|
||||||
ret = proc.wait()
|
for pipe in (proc.stdout, proc.stderr):
|
||||||
|
if pipe:
|
||||||
|
pipe.close()
|
||||||
if ret != 0:
|
if ret != 0:
|
||||||
err = (proc.stderr.read() if proc.stderr else "") or ""
|
raise RuntimeError(f"ffmpeg failed ({ret}): {''.join(err_tail)[-300:]}")
|
||||||
raise RuntimeError(f"ffmpeg failed ({ret}): {err[:300]}")
|
|
||||||
|
|
||||||
|
|
||||||
# --- ffmpeg: universal browser playability --------------------------------------------------
|
# --- ffmpeg: universal browser playability --------------------------------------------------
|
||||||
|
|||||||
@@ -27,6 +27,7 @@ from starlette.middleware.sessions import SessionMiddleware
|
|||||||
from app import auth, state
|
from app import auth, state
|
||||||
from app.config import settings
|
from app.config import settings
|
||||||
from app.db import SessionLocal
|
from app.db import SessionLocal
|
||||||
|
from app.plex import stream as plex_stream
|
||||||
from app.routes import (
|
from app.routes import (
|
||||||
admin,
|
admin,
|
||||||
audit as audit_routes,
|
audit as audit_routes,
|
||||||
@@ -67,6 +68,11 @@ async def lifespan(app: FastAPI):
|
|||||||
" Open the install wizard (internal access only):\n %s",
|
" Open the install wizard (internal access only):\n %s",
|
||||||
url,
|
url,
|
||||||
)
|
)
|
||||||
|
# No HLS session survives a restart (they live in this process), so anything still on disk is
|
||||||
|
# a crashed run's segments — sweep them or they accumulate forever.
|
||||||
|
swept = plex_stream.sweep_orphans()
|
||||||
|
if swept:
|
||||||
|
log.info("swept %d orphaned HLS segment directories", swept)
|
||||||
start_scheduler()
|
start_scheduler()
|
||||||
try:
|
try:
|
||||||
yield
|
yield
|
||||||
|
|||||||
@@ -254,6 +254,27 @@ def wait_for(path: Path, timeout: float = 20.0) -> bool:
|
|||||||
return path.exists()
|
return path.exists()
|
||||||
|
|
||||||
|
|
||||||
|
def sweep_orphans() -> int:
|
||||||
|
"""Delete segment directories no live session owns.
|
||||||
|
|
||||||
|
Sessions live only in THIS process, so at startup every directory under `_HLS_ROOT` is a
|
||||||
|
leftover from a crashed or killed run — and nothing else ever reaps them (the download GC
|
||||||
|
deliberately skips `.plex-hls` as a system tree), so a few restarts mid-playback leave
|
||||||
|
gigabytes of `.ts` segments behind forever."""
|
||||||
|
with _lock:
|
||||||
|
live = {s.dir for s in _sessions.values()}
|
||||||
|
dropped = 0
|
||||||
|
try:
|
||||||
|
entries = list(_HLS_ROOT.iterdir())
|
||||||
|
except OSError: # the root doesn't exist yet — nothing to sweep
|
||||||
|
return 0
|
||||||
|
for p in entries:
|
||||||
|
if p.is_dir() and p not in live:
|
||||||
|
shutil.rmtree(p, ignore_errors=True)
|
||||||
|
dropped += 1
|
||||||
|
return dropped
|
||||||
|
|
||||||
|
|
||||||
def reap_idle() -> int:
|
def reap_idle() -> int:
|
||||||
now = time.time()
|
now = time.time()
|
||||||
dropped = 0
|
dropped = 0
|
||||||
|
|||||||
+41
-11
@@ -341,13 +341,51 @@ def _staging_dir(asset_id: int) -> Path:
|
|||||||
return Path(settings.download_root) / ".staging" / f"asset-{asset_id}"
|
return Path(settings.download_root) / ".staging" / f"asset-{asset_id}"
|
||||||
|
|
||||||
|
|
||||||
|
_THUMB_SUFFIXES = (".jpg", ".jpeg", ".png", ".webp")
|
||||||
|
|
||||||
|
|
||||||
def _find_thumbnail(staging: Path, media: Path) -> Path | None:
|
def _find_thumbnail(staging: Path, media: Path) -> Path | None:
|
||||||
for p in staging.iterdir():
|
for p in staging.iterdir():
|
||||||
if p != media and p.suffix.lower() in (".jpg", ".jpeg", ".png", ".webp"):
|
if p != media and p.suffix.lower() in _THUMB_SUFFIXES:
|
||||||
return p
|
return p
|
||||||
return None
|
return None
|
||||||
|
|
||||||
|
|
||||||
|
def _produced_file(info: dict, staging: Path) -> Path:
|
||||||
|
"""The media file yt-dlp actually wrote.
|
||||||
|
|
||||||
|
`requested_downloads[0].filepath` is the authoritative answer on YouTube, but an arbitrary-URL
|
||||||
|
extractor may not fill it in at all — and `Path("")` is `Path(".")`, which *passes* `.exists()`,
|
||||||
|
so a missing value used to sail past the fallback and blow up two steps later (`with_name` on an
|
||||||
|
empty name: the BBC-news failure). Anything that isn't a real file counts as absent; then fall
|
||||||
|
back to the largest non-thumbnail file left in staging."""
|
||||||
|
req = (info.get("requested_downloads") or [{}])[0]
|
||||||
|
fp = req.get("filepath") or req.get("_filename") or info.get("filepath") or info.get("_filename")
|
||||||
|
if fp:
|
||||||
|
produced = Path(str(fp))
|
||||||
|
if produced.is_file():
|
||||||
|
return produced
|
||||||
|
cands = [
|
||||||
|
p
|
||||||
|
for p in staging.iterdir()
|
||||||
|
if p.is_file() and p.suffix.lower() not in _THUMB_SUFFIXES and not p.name.endswith(".part")
|
||||||
|
]
|
||||||
|
if not cands:
|
||||||
|
raise RuntimeError("yt-dlp produced no output file")
|
||||||
|
return max(cands, key=lambda p: p.stat().st_size)
|
||||||
|
|
||||||
|
|
||||||
|
def _media_info(info: dict) -> dict:
|
||||||
|
"""Unwrap a playlist/multi_video extraction to the entry that carries the download.
|
||||||
|
|
||||||
|
A single non-YouTube page (a news article's video, a multi-rendition embed) can extract as a
|
||||||
|
wrapper whose own dict has no `requested_downloads` — the media lives on the first entry."""
|
||||||
|
entries = [e for e in (info.get("entries") or []) if e]
|
||||||
|
if entries and not info.get("requested_downloads"):
|
||||||
|
return {**info, **entries[0]}
|
||||||
|
return info
|
||||||
|
|
||||||
|
|
||||||
# Errors worth retrying with a different player-client set (YouTube per-client flakiness).
|
# Errors worth retrying with a different player-client set (YouTube per-client flakiness).
|
||||||
_RETRIABLE_MARKERS = (
|
_RETRIABLE_MARKERS = (
|
||||||
"not a bot",
|
"not a bot",
|
||||||
@@ -447,17 +485,9 @@ def _download(job_id: int, asset_id: int, source_kind: str, source_ref: str, spe
|
|||||||
|
|
||||||
_set_job(job_id, phase="downloading", progress=0)
|
_set_job(job_id, phase="downloading", progress=0)
|
||||||
url = service.source_url(source_kind, source_ref)
|
url = service.source_url(source_kind, source_ref)
|
||||||
info = _extract_with_fallback(job_id, asset_id, url, spec, staging)
|
info = _media_info(_extract_with_fallback(job_id, asset_id, url, spec, staging))
|
||||||
|
|
||||||
req = (info.get("requested_downloads") or [{}])[0]
|
|
||||||
produced = Path(req.get("filepath") or "")
|
|
||||||
if not produced.exists():
|
|
||||||
# Fallback: the single media file left in staging (ignore the thumbnail).
|
|
||||||
cands = [p for p in staging.iterdir() if p.suffix.lower() not in (".jpg", ".jpeg", ".png", ".webp")]
|
|
||||||
if not cands:
|
|
||||||
raise RuntimeError("yt-dlp produced no output file")
|
|
||||||
produced = cands[0]
|
|
||||||
|
|
||||||
|
produced = _produced_file(info, staging)
|
||||||
produced = _ensure_browser_playable(job_id, produced, spec, info)
|
produced = _ensure_browser_playable(job_id, produced, spec, info)
|
||||||
ext = produced.suffix.lstrip(".").lower()
|
ext = produced.suffix.lstrip(".").lower()
|
||||||
meta = storage.MediaMeta(
|
meta = storage.MediaMeta(
|
||||||
|
|||||||
@@ -0,0 +1,76 @@
|
|||||||
|
"""Picking the file yt-dlp actually produced, for sources that aren't YouTube.
|
||||||
|
|
||||||
|
The regression these cover: `Path(info["filepath"] or "")` is `Path(".")`, which PASSES `.exists()`,
|
||||||
|
so a missing filepath (an arbitrary-URL extractor) skipped the staging fallback and crashed later
|
||||||
|
with "PosixPath('.') has an empty name" instead of downloading."""
|
||||||
|
import pytest
|
||||||
|
|
||||||
|
from app.downloads.edit import _concat_quote
|
||||||
|
from app.worker import _media_info, _produced_file
|
||||||
|
from pathlib import Path, PurePosixPath
|
||||||
|
|
||||||
|
|
||||||
|
def _staging(tmp_path: Path, *names: str) -> Path:
|
||||||
|
for n in names:
|
||||||
|
p = tmp_path / n
|
||||||
|
p.write_bytes(b"x" * (10 * (names.index(n) + 1)))
|
||||||
|
return tmp_path
|
||||||
|
|
||||||
|
|
||||||
|
class TestProducedFile:
|
||||||
|
def test_uses_the_reported_filepath(self, tmp_path):
|
||||||
|
staging = _staging(tmp_path, "v.mp4", "v.jpg")
|
||||||
|
info = {"requested_downloads": [{"filepath": str(tmp_path / "v.mp4")}]}
|
||||||
|
assert _produced_file(info, staging) == tmp_path / "v.mp4"
|
||||||
|
|
||||||
|
@pytest.mark.parametrize("info", [{}, {"requested_downloads": [{}]}, {"requested_downloads": [{"filepath": ""}]}])
|
||||||
|
def test_missing_filepath_falls_back_to_staging(self, tmp_path, info):
|
||||||
|
staging = _staging(tmp_path, "thumb.jpg", "clip.mp4")
|
||||||
|
assert _produced_file(info, staging) == tmp_path / "clip.mp4"
|
||||||
|
|
||||||
|
def test_stale_filepath_falls_back_to_staging(self, tmp_path):
|
||||||
|
staging = _staging(tmp_path, "clip.mp4")
|
||||||
|
info = {"requested_downloads": [{"filepath": str(tmp_path / "gone.mp4")}]}
|
||||||
|
assert _produced_file(info, staging) == tmp_path / "clip.mp4"
|
||||||
|
|
||||||
|
def test_picks_the_largest_media_file_ignoring_thumbs_and_partials(self, tmp_path):
|
||||||
|
staging = _staging(tmp_path, "small.mp4", "big.mp4", "cover.webp")
|
||||||
|
(tmp_path / "huge.mp4.part").write_bytes(b"x" * 999)
|
||||||
|
assert _produced_file({}, staging) == tmp_path / "big.mp4"
|
||||||
|
|
||||||
|
def test_no_output_at_all_raises(self, tmp_path):
|
||||||
|
staging = _staging(tmp_path, "only.jpg")
|
||||||
|
with pytest.raises(RuntimeError):
|
||||||
|
_produced_file({}, staging)
|
||||||
|
|
||||||
|
|
||||||
|
class TestMediaInfo:
|
||||||
|
def test_playlist_wrapper_unwraps_to_the_entry_that_downloaded(self):
|
||||||
|
info = {"id": "page", "title": "Article", "entries": [{"id": "vid", "requested_downloads": [{"filepath": "/x.mp4"}]}]}
|
||||||
|
assert _media_info(info)["id"] == "vid"
|
||||||
|
|
||||||
|
def test_plain_result_is_untouched(self):
|
||||||
|
info = {"id": "vid", "requested_downloads": [{"filepath": "/x.mp4"}]}
|
||||||
|
assert _media_info(info) is info
|
||||||
|
|
||||||
|
def test_wrapper_that_downloaded_itself_wins_over_its_entries(self):
|
||||||
|
info = {"id": "vid", "requested_downloads": [{"filepath": "/x.mp4"}], "entries": [{"id": "other"}]}
|
||||||
|
assert _media_info(info)["id"] == "vid"
|
||||||
|
|
||||||
|
def test_empty_entries_are_ignored(self):
|
||||||
|
info = {"id": "vid", "entries": [None]}
|
||||||
|
assert _media_info(info)["id"] == "vid"
|
||||||
|
|
||||||
|
|
||||||
|
class TestConcatQuote:
|
||||||
|
# PurePosixPath so the escaping is asserted identically on a Windows dev box and in the
|
||||||
|
# Linux test container (a WindowsPath would eat the backslash as a separator).
|
||||||
|
def test_apostrophe_is_closed_escaped_and_reopened(self):
|
||||||
|
# A pre-0.51.0 file can still be named with an apostrophe; unescaped it breaks the list.
|
||||||
|
assert _concat_quote(PurePosixPath("/m/Don't_Look.mp4")) == "/m/Don'\\''t_Look.mp4"
|
||||||
|
|
||||||
|
def test_backslash_is_doubled(self):
|
||||||
|
assert _concat_quote(PurePosixPath("/m/a\\b.mp4")) == "/m/a\\\\b.mp4"
|
||||||
|
|
||||||
|
def test_ordinary_path_is_unchanged(self):
|
||||||
|
assert _concat_quote(PurePosixPath("/m/clip.mp4")) == "/m/clip.mp4"
|
||||||
Reference in New Issue
Block a user