From 3a683d7feb14f2cbe319a39cc2280e78398c0dce Mon Sep 17 00:00:00 2001 From: Bryan Van Deusen Date: Wed, 1 Jul 2026 21:00:29 -0400 Subject: [PATCH] =?UTF-8?q?fix(agent):=20short=20videos=20failed=20as=20"u?= =?UTF-8?q?nprocessable"=20=E2=80=94=20fps=20filter=20emits=200=20frames?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Root cause of the "no frames sampled from video (unprocessable)" flood (operator-flagged 2026-07-02, whole 62k-70k image block + others): the sampler used `-vf fps=1/4`, and ffmpeg's fps filter emits round(duration/4) frames — which is ZERO for any clip shorter than ~2s. Short animation loops (0.5s, 1.75s — verified against two originals from different artists) are complete, valid h264 videos; ffmpeg decoded them fine, emitted no frames, exited 0, and the agent failed the job as unprocessable. Long videos worked, so only the short-clip class flooded. Fix: sample with select ("first frame always, then one per interval of timestamp") + -fps_mode vfr, and scale=out_range=full so limited-range yuv420p sources don't trip the mjpeg encoder's full-range strictness (secondary failure observed on a 4440x2760 clip). Verified locally against both failing originals (frames extracted, PIL-clean) and a synthetic 15s video (4 frames at t=0/4/8/12 — long-video behavior unchanged). Observability (why this hid for weeks): ffmpeg's stderr was discarded, so every failure logged only "no frames sampled". stderr now goes to a temp file and its tail is logged on any produced-no-frames/timeout failure — the log names the actual ffmpeg reason from now on. Also: frames written before a mid-stream ffmpeg error are now kept (partial > nothing). VERSION → 2026-07-02.1. Co-Authored-By: Claude Fable 5 --- agent/fc_agent/app.py | 2 +- agent/fc_agent/media.py | 76 ++++++++++++++++++++++++++++++----------- 2 files changed, 57 insertions(+), 21 deletions(-) diff --git a/agent/fc_agent/app.py b/agent/fc_agent/app.py index a484a9a..51de0b6 100644 --- a/agent/fc_agent/app.py +++ b/agent/fc_agent/app.py @@ -21,7 +21,7 @@ log = logging.getLogger("fc_agent.app") # Bump on every agent change. The page embeds this and /status reports it; the UI # warns to reload when they differ — so a stale browser-cached page can't be # mistaken for "the new image didn't deploy". (Belt-and-braces with no-store.) -VERSION = "2026-07-01.10 · fix Status freeze (conchint.textContent destroyed #capn)" +VERSION = "2026-07-02.1 · short videos sample again (select, not fps) + ffmpeg errors logged" logbuf.install() cfg = Config.from_env() diff --git a/agent/fc_agent/media.py b/agent/fc_agent/media.py index ba70754..48c9ed5 100644 --- a/agent/fc_agent/media.py +++ b/agent/fc_agent/media.py @@ -2,6 +2,7 @@ (ffmpeg) at the cadence FC sends — so a video becomes a bag of per-frame instances, each with a timestamp.""" import io +import logging import os import subprocess import tempfile @@ -9,6 +10,8 @@ import time from PIL import Image, ImageFile +log = logging.getLogger("fc_agent.media") + # Load slightly-truncated images (a few missing trailing bytes) instead of # raising — matches the server embedder. These are common in scraped libraries # and would otherwise fail the job 3× then error (operator-flagged 2026-06-30). @@ -134,29 +137,62 @@ def sample_frames_from_url( interval = max(0.5, float(interval_seconds or 4.0)) cap = max(1, int(max_frames or 64)) hdr = ["-headers", headers] if headers else [] + # select (NOT the fps filter): always keep the FIRST frame, then one per + # `interval` seconds of timestamp. fps=1/N emits round(duration/N) frames, + # which is ZERO for any clip shorter than ~N/2 seconds — a whole class of + # short animation loops failed as "unprocessable" that way (operator-flagged + # 2026-07-02: 0.5s/1.75s clips). scale=out_range=full converts limited-range + # yuv420p to full range so the mjpeg (jpg) encoder accepts it at default + # strictness instead of erroring on "non full-range YUV". + vf = ( + f"select='isnan(prev_selected_t)+gte(t-prev_selected_t\\,{interval})'," + "scale=out_range=full" + ) with tempfile.TemporaryDirectory() as tmp: pattern = os.path.join(tmp, "f_%05d.jpg") cmd = ["ffmpeg", "-nostdin", "-loglevel", "error", *_RECONNECT, *hdr, - "-i", url, "-vf", f"fps=1/{interval}", "-frames:v", str(cap), - "-q:v", "3", pattern] + "-i", url, "-vf", vf, "-fps_mode", "vfr", + "-frames:v", str(cap), "-q:v", "3", pattern] + # ffmpeg's stderr goes to a file (not a PIPE, which could fill and + # deadlock; not DEVNULL, which is how a filter bug hid as "unprocessable" + # for weeks) — on failure its tail is logged so the operator can see WHY. + errpath = os.path.join(tmp, "stderr.txt") try: - proc = subprocess.Popen( - cmd, stdin=subprocess.DEVNULL, - stdout=subprocess.DEVNULL, stderr=subprocess.DEVNULL, - ) + with open(errpath, "wb") as errf: + proc = subprocess.Popen( + cmd, stdin=subprocess.DEVNULL, + stdout=subprocess.DEVNULL, stderr=errf, + ) + # Poll rather than block, so a Stop (or the per-video timeout) can + # kill a slow/wedged ffmpeg promptly instead of waiting it out. + start = time.monotonic() + while True: + try: + proc.wait(timeout=0.5) + break + except subprocess.TimeoutExpired: + stopped = should_stop and should_stop() + if stopped or (time.monotonic() - start > timeout): + _terminate(proc) + if not stopped: + log.warning("ffmpeg timed out after %.0fs: %s", + timeout, url) + return [] except (OSError, ValueError): return [] - # Poll rather than block, so a Stop (or the per-video timeout) can kill a - # slow/wedged ffmpeg promptly instead of waiting it out. - start = time.monotonic() - while True: - try: - proc.wait(timeout=0.5) - break - except subprocess.TimeoutExpired: - if (should_stop and should_stop()) or (time.monotonic() - start > timeout): - _terminate(proc) - return [] - if proc.returncode != 0: - return [] - return _collect_frames(tmp, interval, cap) + frames = _collect_frames(tmp, interval, cap) + if not frames: + log.warning("ffmpeg produced no frames (exit %s) for %s — stderr: %s", + proc.returncode, url, _tail(errpath)) + return frames + + +def _tail(path: str, limit: int = 300) -> str: + """Last `limit` chars of a (stderr) file, flattened — for failure logs.""" + try: + with open(path, "rb") as f: + f.seek(0, os.SEEK_END) + f.seek(max(0, f.tell() - limit)) + return f.read().decode("utf-8", "replace").replace("\n", " ").strip() + except OSError: + return "?"