From 641a52d1ad8ba935f2db1b4a688e39570bb16707 Mon Sep 17 00:00:00 2001
From: Bryan Van Deusen <bryan.vandeusen@fabledsword.com>
Date: Sun, 26 Apr 2026 11:09:41 -0400
Subject: [PATCH] diag(ml): per-stage timing + file size in video inference
 logs
MIME-Version: 1.0
Content-Type: text/plain; charset=UTF-8
Content-Transfer-Encoding: 8bit

Adds per-call instrumentation to _run_video_inference so we can see
where the cost goes on slow videos: frame extraction (ffmpeg seeks),
WD14, or SigLIP. Also captures file size to correlate slowness with
file characteristics.

Output shape:
  tag_and_embed: video 7384 timings extract=12.3s wd14=24.1s
  siglip=82.6s frames=10/10 file_size=412.5MB

Investigating a soft-time-limit storm where the deployed code has
soft_time_limit=900 but workers are firing limits at ~120s intervals.
This patch is pure observability — no behavior change.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
---
 app/tasks/ml.py | 29 +++++++++++++++++++++++++++++
 1 file changed, 29 insertions(+)

diff --git a/app/tasks/ml.py b/app/tasks/ml.py
index 61d8cf6..39a8c4f 100644
--- a/app/tasks/ml.py
+++ b/app/tasks/ml.py
@@ -44,26 +44,55 @@ def _run_video_inference(image, wd14, siglip) -> tuple[list[dict], np.ndarray] |
     distance behavior since the pgvector index normalizes as needed.
 
     Returns (predictions, embedding) or None if frame extraction fails.
+
+    Emits per-stage timing on every call so we can see which phase is the
+    cost driver on slow videos: frame extraction (ffmpeg seeks), WD14
+    inference, or SigLIP inference. Also captures file size so we can
+    correlate slowness with file characteristics.
     """
     import shutil
     from app.utils.image_importer import extract_video_frames
 
+    try:
+        file_size_mb = os.path.getsize(image.filepath) / (1024 * 1024)
+    except OSError:
+        file_size_mb = -1.0
+
+    t_extract_start = time.time()
     frame_paths = extract_video_frames(image.filepath, count=VIDEO_ML_FRAMES)
+    t_extract = time.time() - t_extract_start
     if not frame_paths:
+        log.info(
+            f"tag_and_embed: video {image.id} extract_video_frames returned 0 frames "
+            f"(extract={t_extract:.2f}s file_size={file_size_mb:.1f}MB)"
+        )
         return None
 
     tmpdir = os.path.dirname(frame_paths[0])
     try:
         best: dict[tuple[str, str], dict] = {}
         embeddings: list[np.ndarray] = []
+        wd14_total = 0.0
+        siglip_total = 0.0
         for fp in frame_paths:
+            t0 = time.time()
             raw = wd14.infer_filtered(fp, min_any=WD14_STORE_FLOOR)
+            wd14_total += time.time() - t0
             for pred in raw:
                 key = (pred['name'], pred['category'])
                 prev = best.get(key)
                 if prev is None or pred['confidence'] > prev['confidence']:
                     best[key] = pred
+            t0 = time.time()
             embeddings.append(siglip.infer(fp))
+            siglip_total += time.time() - t0
+
+        log.info(
+            f"tag_and_embed: video {image.id} timings extract={t_extract:.2f}s "
+            f"wd14={wd14_total:.2f}s siglip={siglip_total:.2f}s "
+            f"frames={len(frame_paths)}/{VIDEO_ML_FRAMES} "
+            f"file_size={file_size_mb:.1f}MB"
+        )
 
         if not embeddings:
             return None