cista/preview.py

@@ -4,6 +4,7 @@ import io
 import mimetypes
 import urllib.parse
 from pathlib import PurePosixPath
+from time import perf_counter
 from urllib.parse import unquote
 from wsgiref.handlers import format_date_time
 
@@ -68,10 +69,16 @@ def dispatch(path, quality, maxsize, maxzoom):
 
 
 def process_image(path, *, maxsize, quality):
+    t_load_start = perf_counter()
     img = Image.open(path)
-    w, h = img.size
-    img.thumbnail((min(w, maxsize), min(h, maxsize)))
-    # Fix rotation based on EXIF data
+    # Force decode to include I/O in load timing
+    img.load()
+    t_load_end = perf_counter()
+
+    # Resize and orientation fix (processing)
+    orig_w, orig_h = img.size
+    t_proc_start = perf_counter()
+    img.thumbnail((min(orig_w, maxsize), min(orig_h, maxsize)))
     try:
         rotate_values = {3: 180, 6: 270, 8: 90}
         orientation = img.getexif().get(274)
@@ -80,27 +87,72 @@ def process_image(path, *, maxsize, quality):
             img = img.rotate(rotate_values[orientation], expand=True)
     except Exception as e:
         logger.error(f"Error rotating preview image: {e}")
-    # Save as webp
+    t_proc_end = perf_counter()
+
+    # Save as AVIF
     imgdata = io.BytesIO()
-    print("Image quality", quality)
+    t_save_start = perf_counter()
     img.save(imgdata, format="avif", quality=quality)
-    return imgdata.getvalue()
+    t_save_end = perf_counter()
+
+    ret = imgdata.getvalue()
+
+    load_ms = (t_load_end - t_load_start) * 1000
+    proc_ms = (t_proc_end - t_proc_start) * 1000
+    save_ms = (t_save_end - t_save_start) * 1000
+    logger.debug(
+        "Preview image %s: load=%.1fms process=%.1fms save=%.1fms out=%.1fKB %dx%d -> %dx%d q=%d",
+        path.name,
+        load_ms,
+        proc_ms,
+        save_ms,
+        len(ret) / 1024,
+        orig_w,
+        orig_h,
+        getattr(img, "width", 0),
+        getattr(img, "height", 0),
+        quality,
+    )
+
+    return ret
 
 
 def process_pdf(path, *, maxsize, maxzoom, quality, page_number=0):
+    t_load_start = perf_counter()
     pdf = fitz.open(path)
     page = pdf.load_page(page_number)
     w, h = page.rect[2:4]
     zoom = min(maxsize / w, maxsize / h, maxzoom)
     mat = fitz.Matrix(zoom, zoom)
-    pix = page.get_pixmap(matrix=mat)
-    return pix.pil_tobytes(format="avif", quality=quality, method=4)
+    pix = page.get_pixmap(matrix=mat)  # type: ignore[attr-defined]
+    t_load_end = perf_counter()
+
+    t_save_start = perf_counter()
+    ret = pix.pil_tobytes(format="avif", quality=quality, method=4)
+    t_save_end = perf_counter()
+
+    logger.debug(
+        "Preview pdf %s: load+render=%.1fms save=%.1fms out=%.1fKB page=%d zoom=%.2f",
+        path.name,
+        (t_load_end - t_load_start) * 1000,
+        (t_save_end - t_save_start) * 1000,
+        len(ret) / 1024,
+        page_number,
+        zoom,
+    )
+
+    return ret
 
 
 def process_video(path, *, maxsize, quality):
     frame = None
     imgdata = io.BytesIO()
     istream = ostream = icc = occ = frame = None
+    t_load_start = perf_counter()
+    # Initialize to avoid "possibly unbound" in static analysis when exceptions occur
+    t_load_end = t_load_start
+    t_save_start = t_load_start
+    t_save_end = t_load_start
     with (
         av.open(str(path)) as icontainer,
         av.open(imgdata, "w", format="avif") as ocontainer,
@@ -150,9 +202,13 @@ def process_video(path, *, maxsize, quality):
                     )
                 else:
                     logger.exception(f"Error rotating video frame: {e}")
+        t_load_end = perf_counter()
 
+        t_save_start = perf_counter()
         crf = str(int(63 * (1 - quality / 100) ** 2))  # Closely matching PIL quality-%
-        ostream = ocontainer.add_stream("av1", options={"crf": crf})
+        ostream = ocontainer.add_stream(
+            "av1", options={"crf": crf, "usage": "realtime"}
+        )
         assert isinstance(ostream, av.VideoStream)
         ostream.width = frame.width
         ostream.height = frame.height
@@ -167,8 +223,22 @@ def process_video(path, *, maxsize, quality):
 
         ocontainer.mux(ostream.encode(frame))
         ocontainer.mux(ostream.encode(None))  # Flush the stream
+        t_save_end = perf_counter()
 
+    # Capture frame dimensions before cleanup
+    fw = getattr(frame, "width", 0) if frame else 0
+    fh = getattr(frame, "height", 0) if frame else 0
     ret = imgdata.getvalue()
+    logger.debug(
+        "Preview video %s: load+decode=%.1fms save=%.1fms out=%.1fKB dims=%dx%d q=%d",
+        path.name,
+        (t_load_end - t_load_start) * 1000,
+        (t_save_end - t_save_start) * 1000,
+        len(ret) / 1024,
+        fw,
+        fh,
+        quality,
+    )
     del imgdata, istream, ostream, icc, occ, frame
     gc.collect()
     return ret