diff --git a/cista/preview.py b/cista/preview.py index a75c662..d586440 100644 --- a/cista/preview.py +++ b/cista/preview.py @@ -2,7 +2,6 @@ import asyncio import gc import io import mimetypes -import os import struct import sys import threading @@ -20,10 +19,8 @@ import msgspec import av import fitz # PyMuPDF import numpy as np -import pillow_heif import pyvips from blake3 import blake3 -from PIL import Image from sanic import Blueprint, empty, raw, redirect from sanic.exceptions import NotFound from sanic.log import logger @@ -32,8 +29,6 @@ from cista import auth, config from cista.preview_worker import PreviewRequest, PreviewResponse from cista.util.filename import sanitize -pillow_heif.register_heif_opener() - bp = Blueprint("preview", url_prefix="/preview") @@ -85,7 +80,6 @@ _active_procs: set[asyncio.subprocess.Process] = set() _preview_pool = None _preview_pool_lock = asyncio.Lock() AVIF_FAST_EFFORT = 0 -FORCE_PIL = os.environ.get("CISTA_PIL") == "1" WORKER_CHECKSUM_BYTES = 32 WORKER_MAX_JSON_BYTES = 1_000_000 @@ -135,7 +129,11 @@ class _PreviewWorker: resp = msgspec.json.decode(meta_raw, type=PreviewResponse) if not resp.ok: - raise PreviewError(resp.error or "preview worker error") + raise PreviewError( + resp.error or "preview worker error", + stderr=resp.stderr, + backend=resp.backend, + ) return payload or None, resp async def kill(self) -> None: @@ -207,7 +205,7 @@ class _PreviewWorkerPool: except WorkerChecksumError: replace = True logger.error("Preview checksum mismatch for %s", filepath.name) - raise PreviewError(filepath.name) + raise PreviewError(f"worker checksum mismatch for {filepath.name}") except PreviewError: raise except ( @@ -223,7 +221,9 @@ class _PreviewWorkerPool: logger.warning( "Preview worker protocol failure for %s: %s", filepath.name, e ) - raise PreviewError(filepath.name) + raise PreviewError( + f"worker protocol failure for {filepath.name}: {e}" + ) finally: if replace: await self._replace_worker(worker) @@ -295,6 +295,17 @@ class PreviewTimeout(Exception): class PreviewError(Exception): """Raised when the preview subprocess exits with a non-zero status.""" + def __init__( + self, + message: str, + *, + stderr: str | None = None, + backend: str | None = None, + ): + super().__init__(message) + self.stderr = stderr + self.backend = backend + async def _run_preview_process( filepath, quality: int, maxsize: int, maxzoom: float @@ -302,22 +313,10 @@ async def _run_preview_process( """Run preview request in a persistent worker process.""" await start_preview_workers() if _preview_pool is None: - raise PreviewError(filepath.name) + raise PreviewError(f"preview worker pool unavailable for {filepath.name}") return await _preview_pool.run(filepath, quality, maxsize, maxzoom) -# Map EXIF Orientation value to a corresponding PIL transpose -EXIF_ORI = { - 2: Image.Transpose.FLIP_LEFT_RIGHT, - 3: Image.Transpose.ROTATE_180, - 4: Image.Transpose.FLIP_TOP_BOTTOM, - 5: Image.Transpose.TRANSPOSE, - 6: Image.Transpose.ROTATE_270, - 7: Image.Transpose.TRANSVERSE, - 8: Image.Transpose.ROTATE_90, -} - - DOC_PREVIEW_SUFFIXES = {".pdf", ".xps", ".epub", ".mobi"} @@ -368,7 +367,15 @@ async def preview(req, path): ) except PreviewTimeout: return empty(504) - except PreviewError: + except PreviewError as e: + if e.backend: + req.ctx._log_extra = e.backend + detail = str(e) + if detail == "preview worker error" and e.stderr: + captured = e.stderr.strip() + if captured: + detail = captured.splitlines()[0] + logger.error("%s preview: %s", filepath, detail) return empty(422) if preview_resp and preview_resp.backend: if preview_resp.timings: @@ -403,28 +410,26 @@ async def preview(req, path): def dispatch(path, quality, maxsize, maxzoom): + backend = "unknown" try: if path.suffix.lower() in DOC_PREVIEW_SUFFIXES: + backend = "pdf" return process_pdf(path, quality=quality, maxsize=maxsize, maxzoom=maxzoom) mime_type, _ = mimetypes.guess_type(path.name) if mime_type and mime_type.startswith("video/"): + backend = "video" return process_video(path, quality=quality, maxsize=maxsize) if mime_type and mime_type.startswith("image/"): + backend = "pyvips" return process_image(path, quality=quality, maxsize=maxsize) except ValueError as e: - logger.warning(f"Cannot generate preview for {path}: {e}") + return None, PreviewResponse(ok=False, backend=backend, error=str(e)) except Exception as e: - logger.exception(f"Error generating preview for {path}: {e}") - return None, PreviewResponse(ok=False) + return None, PreviewResponse(ok=False, backend=backend, error=str(e)) + return None, PreviewResponse(ok=False, backend=backend, error="preview unsupported") def process_image(path, *, maxsize, quality): - return process_image_with_timing(path, maxsize=maxsize, quality=quality) - - -def process_image_with_timing(path, *, maxsize, quality): - if FORCE_PIL: - return process_image_pillow(path, maxsize=maxsize, quality=quality) return process_image_pyvips(path, maxsize=maxsize, quality=quality) @@ -451,45 +456,6 @@ def process_image_pyvips(path, *, maxsize, quality): ) -def process_image_pillow(path, *, maxsize, quality): - t_load = perf_counter() - with Image.open(path) as img: - # Force decode to include I/O in load timing - img.load() - t_proc = perf_counter() - # Resize - w, h = img.size - img.thumbnail((min(w, maxsize), min(h, maxsize))) - # Transpose pixels according to EXIF Orientation - orientation = img.getexif().get(274, 1) - if orientation in EXIF_ORI: - img = img.transpose(EXIF_ORI[orientation]) - # Save as AVIF - imgdata = io.BytesIO() - t_save = perf_counter() - img.save( - imgdata, - format="avif", - quality=quality, - speed=10, - max_threads=1, - avif=1, - ) - - t_end = perf_counter() - ret = imgdata.getvalue() - - load_ms = (t_proc - t_load) * 1000 - proc_ms = (t_save - t_proc) * 1000 - save_ms = (t_end - t_save) * 1000 - return ret, PreviewResponse( - ok=True, - mime="image/avif", - backend="pillow", - timings=[round(load_ms, 1), round(proc_ms, 1), round(save_ms, 1)], - ) - - def process_pdf(path, *, maxsize, maxzoom, quality, page_number=0): t_load_start = perf_counter() pdf = fitz.open(path) @@ -501,19 +467,13 @@ def process_pdf(path, *, maxsize, maxzoom, quality, page_number=0): t_load_end = perf_counter() t_save_start = perf_counter() - if FORCE_PIL: - ret = pix.pil_tobytes( - format="avif", quality=quality, speed=10, max_threads=1, avif=1 - ) - backend = "pdf" - else: - img = pyvips.Image.new_from_memory( - pix.samples_mv, pix.width, pix.height, pix.n, "uchar" - ) - ret = img.write_to_buffer( - ".avif", Q=quality, effort=AVIF_FAST_EFFORT, strip=True - ) - backend = "pdf+pyvips" + img = pyvips.Image.new_from_memory( + pix.samples_mv, pix.width, pix.height, pix.n, "uchar" + ) + ret = img.write_to_buffer( + ".avif", Q=quality, effort=AVIF_FAST_EFFORT, strip=True + ) + backend = "pdf+pyvips" t_save_end = perf_counter() return ret, PreviewResponse( diff --git a/cista/preview_worker.py b/cista/preview_worker.py index 791f2a4..40a8e2a 100644 --- a/cista/preview_worker.py +++ b/cista/preview_worker.py @@ -10,6 +10,8 @@ where packet = (uint32 json size)(uint32 payload size)(json)(binary payload). """ import logging +import contextlib +import io import struct import sys from pathlib import Path @@ -31,6 +33,7 @@ class PreviewResponse(msgspec.Struct, omit_defaults=True): backend: str | None = None timings: list[float] | None = None error: str | None = None + stderr: str | None = None _enc = msgspec.json.Encoder() @@ -70,14 +73,34 @@ def _run_loop() -> None: line = sys.stdin.buffer.readline() if not line: return + stderr_capture = io.StringIO() + handler = logging.StreamHandler(stderr_capture) + root_logger = logging.getLogger() + root_logger.addHandler(handler) try: - req = _dec_req.decode(line) - result, resp = dispatch( - Path(req.path), req.quality, req.maxsize, req.maxzoom - ) + with contextlib.redirect_stderr(stderr_capture): + req = _dec_req.decode(line) + result, resp = dispatch( + Path(req.path), req.quality, req.maxsize, req.maxzoom + ) + if not resp.ok: + captured = stderr_capture.getvalue().strip() + if captured: + resp = PreviewResponse( + ok=False, + backend=resp.backend, + error=resp.error, + stderr=captured, + ) _write_response(resp, result or b"") except Exception as e: - _write_response(PreviewResponse(ok=False, error=str(e)), b"") + captured = stderr_capture.getvalue().strip() + _write_response( + PreviewResponse(ok=False, error=str(e), stderr=captured or None), b"" + ) + finally: + root_logger.removeHandler(handler) + handler.close() def main() -> None: diff --git a/cista/sanic_logging.py b/cista/sanic_logging.py index 4acc49f..0325d4a 100644 --- a/cista/sanic_logging.py +++ b/cista/sanic_logging.py @@ -236,7 +236,8 @@ class _EmojiFormatter(logging.Formatter): def format(self, record: logging.LogRecord) -> str: emoji = _LEVEL_EMOJI.get(record.levelno, "▪️") - return f"{emoji} {record.getMessage()}" + sep = " " if record.levelno in (logging.INFO, logging.WARNING) else " " + return f"{emoji}{sep}{record.getMessage()}" def configure_main_logging() -> None: