Compare commits

..
5 Commits
Author SHA1 Message Date
LeoVasanko 953ec628a0 Add -nostdin to ffmpeg preview conversions to suppress keyboard prompts 2026-08-11 05:32:27 +00:00
LeoVasanko e678c8c267 Put the failing ffmpeg command on its own line in error messages 2026-08-11 05:31:30 +00:00
LeoVasanko 69d58f99e3 Drop noisy ffmpeg fallback for non-HEIC images, quiet ffmpeg output
A corrupt TIFF in production produced a wall of ffmpeg error output:
pyvips could not decode it, the generic ffmpeg fallback was tried, and
ffmpeg's TIFF decoder failed just the same — with banner, configuration
and stream-mapping spam included.

- Non-HEIC images are now decoded by pyvips only; a pyvips failure
  raises a clean one-line ValueError ("cannot decode image: ...", a 422
  like any other undecodable file) instead of invoking ffmpeg. The
  ffmpeg path is kept for HEIC/HEIF, where pyvips genuinely falls short
  (tile assembly, HDR metadata).
- ffmpeg runs with -hide_banner -loglevel error -nostats: error output
  is still shown on failure, without the version/configuration/progress
  noise. The -s insertion index no longer depends on fixed positions.
2026-08-11 05:29:32 +00:00
LeoVasanko 36764885ed Silence pyvips deprecation and INFO spam in preview worker
- AVIF saves: replace deprecated strip=True with keep="none" (libvips
  8.15+; production already runs a version that deprecates strip).
- Set the pyvips logger to WARNING in the worker: its INFO messages
  ("threadpool completed ...") are pure spam on every operation.
2026-08-11 05:11:44 +00:00
LeoVasanko 5a82560cf2 Format preview worker logs like the main process, tagged with worker pid
Worker stderr is now inherited by the parent, so its log lines land in the
server log — but they arrived with the default logging format and a noisy
"preview-worker config=..." line at every spawn.

- Extract the emoji level-prefix formatting from cista.sanic_logging into
  cista.util.logformat, which has no Sanic dependency (the worker must not
  import Sanic: import-time prints could corrupt the stdout protocol).
- Worker configures its stderr handler with the same emoji prefixes plus a
  worker[pid] tag, and the config-loaded info message is removed.
2026-08-11 05:05:07 +00:00
3 changed files with 80 additions and 48 deletions
+40 -17
View File
@@ -17,6 +17,7 @@ import gc
import io
import logging
import mimetypes
import os
import shlex
import struct
import subprocess
@@ -33,9 +34,19 @@ import pyvips
from blake3 import blake3
from cista import config
from cista.util.logformat import format_level_prefix
logger = logging.getLogger(__name__)
class _WorkerLogFormatter(logging.Formatter):
"""Emoji level prefix like the main process, tagged with the worker pid."""
def format(self, record: logging.LogRecord) -> str:
prefix = format_level_prefix(record.levelno)
return f"{prefix}worker[{os.getpid()}]: {record.getMessage()}"
AVIF_FAST_EFFORT = 0
DOC_PREVIEW_SUFFIXES = {".pdf", ".xps", ".epub", ".mobi"}
@@ -202,6 +213,13 @@ def _image_via_ffmpeg(path: Path, maxsize: int, quality: int) -> bytes:
tmp_path = tmp_f.name
cmd = [
"ffmpeg",
# Keep error messages, drop the banner/config/stream-mapping spam.
"-hide_banner",
"-loglevel",
"error",
"-nostats",
# No interactive keyboard prompts ("Press [q] to stop ...").
"-nostdin",
"-y",
"-i",
str(path),
@@ -222,8 +240,9 @@ def _image_via_ffmpeg(path: Path, maxsize: int, quality: int) -> bytes:
new_w = int(w * scale)
new_h = int(h * scale)
# insert -s <wxh> right after the input file
cmd.insert(4, "-s")
cmd.insert(5, f"{new_w}x{new_h}")
input_index = cmd.index(str(path)) + 1
cmd.insert(input_index, "-s")
cmd.insert(input_index + 1, f"{new_w}x{new_h}")
try:
try:
# stdin=DEVNULL is critical: ffmpeg must not inherit the worker's
@@ -243,10 +262,10 @@ def _image_via_ffmpeg(path: Path, maxsize: int, quality: int) -> bytes:
stderr = (e.stderr or b"").decode(errors="replace").strip()
if stderr:
raise RuntimeError(
f"ffmpeg failed (exit {e.returncode}): {shell_cmd}\n{stderr}"
f"ffmpeg failed (exit {e.returncode}):\n{shell_cmd}\n{stderr}"
) from e
raise RuntimeError(
f"ffmpeg failed (exit {e.returncode}): {shell_cmd}"
f"ffmpeg failed (exit {e.returncode}):\n{shell_cmd}"
) from e
with Path(tmp_path).open("rb") as f:
return f.read()
@@ -274,9 +293,10 @@ def process_image_pyvips(path, *, maxsize, quality):
height=height,
)
# Other image formats: pyvips first, ffmpeg fallback.
# Other image formats: pyvips only. ffmpeg is not a useful fallback
# here — when pyvips cannot decode a file, ffmpeg's image decoders
# cannot either, and their failure output is far noisier.
load_opts = {"access": "sequential"}
orig_w = orig_h = None
try:
img = pyvips.Image.new_from_file(str(path), **load_opts)
img = img.autorot()
@@ -288,13 +308,11 @@ def process_image_pyvips(path, *, maxsize, quality):
".avif",
Q=quality,
effort=AVIF_FAST_EFFORT,
strip=True,
keep="none",
)
backend = "pyvips"
except pyvips.error.Error:
orig_w, orig_h = None, None
ret = _image_via_ffmpeg(path, maxsize, quality)
backend = "ffmpeg"
except pyvips.error.Error as e:
raise ValueError(f"cannot decode image: {e}") from e
backend = "pyvips"
t_end = perf_counter()
return ret, PreviewResponse(
@@ -320,7 +338,7 @@ def process_image_buffer(data: bytes, *, quality, maxsize, maxzoom):
".avif",
Q=quality,
effort=AVIF_FAST_EFFORT,
strip=True,
keep="none",
)
t_end = perf_counter()
@@ -348,7 +366,7 @@ def process_pdf(path, *, maxsize, maxzoom, quality, page_number=0):
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)
ret = img.write_to_buffer(".avif", Q=quality, effort=AVIF_FAST_EFFORT, keep="none")
backend = "pdf+pyvips"
t_save_end = perf_counter()
@@ -554,11 +572,16 @@ def _run_loop() -> None:
def main() -> None:
# Configure all log output to stderr before any imports that may emit logs.
logging.basicConfig(stream=sys.stderr, level=logging.INFO)
# Configure all log output to stderr before any imports that may emit
# logs. stderr is inherited by the parent, so this lands in the server
# log, formatted like the main process and tagged with the worker pid.
handler = logging.StreamHandler(sys.stderr)
handler.setFormatter(_WorkerLogFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])
# pyvips is chatty at INFO ("threadpool completed ..." per operation).
logging.getLogger("pyvips").setLevel(logging.WARNING)
try:
config.load_config()
logger.info("preview-worker config=%s", config.conffile)
except Exception:
logger.exception("preview-worker failed to load config at startup")
if len(sys.argv) > 1:
+3 -31
View File
@@ -3,11 +3,13 @@
import logging
import os
import sys
import unicodedata
from ipaddress import IPv6Address
from sanic.log import LOGGING_CONFIG_DEFAULTS
from cista.util.logformat import EmojiFormatter as _EmojiFormatter
from cista.util.logformat import display_width as _display_width
logger = logging.getLogger("cista.access")
@@ -132,14 +134,6 @@ def format_duration_ms(duration_ms: float) -> str:
return f"{hours}h{minutes}m"
def _display_width(text: str) -> int:
return sum(
1 + (unicodedata.east_asian_width(c) in "FW")
for c in text
if unicodedata.category(c) != "Mn"
)
def _format_left(label: str) -> str:
return label[:19].ljust(19)
@@ -279,28 +273,6 @@ def configure_access_logging() -> None:
logger.propagate = False
_LEVEL_EMOJI = {
logging.DEBUG: "🔍",
logging.INFO: "", # noqa: RUF001
logging.WARNING: "⚠️",
logging.ERROR: "🛑",
logging.CRITICAL: "🛑",
}
def _format_level_prefix(levelno: int) -> str:
emoji = _LEVEL_EMOJI.get(levelno, "▪️")
prefix = f"{emoji} "
return prefix + (" " * max(0, 3 - _display_width(prefix)))
class _EmojiFormatter(logging.Formatter):
"""Compact formatter: emoji + message, no timestamp/level text/logger name."""
def format(self, record: logging.LogRecord) -> str:
return _format_level_prefix(record.levelno) + record.getMessage()
def configure_main_logging() -> None:
"""Replace Sanic's verbose 'Main yyyy-mm-dd INFO:' prefix with emoji-only format.
+37
View File
@@ -0,0 +1,37 @@
"""Shared log formatting helpers with no Sanic dependency.
Used by the main process (cista.sanic_logging) and by the preview worker
subprocess, which must not import Sanic.
"""
import logging
import unicodedata
LEVEL_EMOJI = {
logging.DEBUG: "🔍",
logging.INFO: "", # noqa: RUF001
logging.WARNING: "⚠️",
logging.ERROR: "🛑",
logging.CRITICAL: "🛑",
}
def display_width(text: str) -> int:
return sum(
1 + (unicodedata.east_asian_width(c) in "FW")
for c in text
if unicodedata.category(c) != "Mn"
)
def format_level_prefix(levelno: int) -> str:
emoji = LEVEL_EMOJI.get(levelno, "▪️")
prefix = f"{emoji} "
return prefix + (" " * max(0, 3 - display_width(prefix)))
class EmojiFormatter(logging.Formatter):
"""Compact formatter: emoji + message, no timestamp/level text/logger name."""
def format(self, record: logging.LogRecord) -> str:
return format_level_prefix(record.levelno) + record.getMessage()