Compare commits
| Author | SHA1 | Date | |
|---|---|---|---|
|
|
d5a59d9eab |
+11
@@ -130,3 +130,14 @@ models/**/*.safetensors
|
|||||||
models/**/*.index
|
models/**/*.index
|
||||||
!models/**/.gitkeep
|
!models/**/.gitkeep
|
||||||
.github
|
.github
|
||||||
|
|
||||||
|
# Runtime job store. gateway/data/jobs.sqlite3 is a live SQLite database the
|
||||||
|
# service writes to on every job — including every test run — so a tracked copy
|
||||||
|
# shows up as a modified file after any use of the gateway, and can carry job
|
||||||
|
# rows (customer filenames among them) into the repository. It is state, not
|
||||||
|
# source; the schema is created on startup.
|
||||||
|
gateway/data/jobs.sqlite3
|
||||||
|
gateway/data/jobs.sqlite3-wal
|
||||||
|
gateway/data/jobs.sqlite3-shm
|
||||||
|
gateway/data/jobs_spool/
|
||||||
|
!gateway/data/jobs_spool/.gitkeep
|
||||||
|
|||||||
@@ -416,14 +416,33 @@ async def merge_documents(
|
|||||||
)
|
)
|
||||||
files_bytes.append(data)
|
files_bytes.append(data)
|
||||||
|
|
||||||
|
# A manifest that could not be parsed used to fall through to "all pages of
|
||||||
|
# every file". The merge then *succeeded*, with content the caller never
|
||||||
|
# asked for and no indication anywhere that its page selection had been
|
||||||
|
# discarded — the worst available failure mode. A manifest that was sent
|
||||||
|
# and cannot be honoured is now refused.
|
||||||
parsed_manifest: list[dict] = []
|
parsed_manifest: list[dict] = []
|
||||||
if manifest and manifest.strip():
|
if manifest and manifest.strip():
|
||||||
try:
|
try:
|
||||||
parsed = json.loads(manifest)
|
parsed = json.loads(manifest)
|
||||||
if isinstance(parsed, list):
|
except json.JSONDecodeError as exc:
|
||||||
parsed_manifest = parsed
|
raise HTTPException(
|
||||||
except Exception:
|
status_code=status.HTTP_400_BAD_REQUEST,
|
||||||
pass
|
detail=(
|
||||||
|
f"Merge manifest is not valid JSON ({exc.msg} at position {exc.pos}). "
|
||||||
|
"Omit the manifest to merge all pages of every file."
|
||||||
|
),
|
||||||
|
) from exc
|
||||||
|
if not isinstance(parsed, list):
|
||||||
|
raise HTTPException(
|
||||||
|
status_code=status.HTTP_400_BAD_REQUEST,
|
||||||
|
detail=(
|
||||||
|
"Merge manifest must be a JSON array of "
|
||||||
|
'{"fileIndex": int, "pages": "all" | "1,3-5"} entries; '
|
||||||
|
f"received {type(parsed).__name__}."
|
||||||
|
),
|
||||||
|
)
|
||||||
|
parsed_manifest = parsed
|
||||||
|
|
||||||
if not parsed_manifest:
|
if not parsed_manifest:
|
||||||
parsed_manifest = [{"fileIndex": idx, "pages": "all"} for idx in range(len(files))]
|
parsed_manifest = [{"fileIndex": idx, "pages": "all"} for idx in range(len(files))]
|
||||||
|
|||||||
@@ -4,12 +4,12 @@ import uuid
|
|||||||
from fastapi import APIRouter, HTTPException, Response, status
|
from fastapi import APIRouter, HTTPException, Response, status
|
||||||
from pydantic import BaseModel
|
from pydantic import BaseModel
|
||||||
|
|
||||||
from app.services import engine
|
from app.services import engine, logs
|
||||||
from app.services.convert.http_headers import content_disposition_attachment
|
from app.services.convert.http_headers import content_disposition_attachment
|
||||||
from app.services.store import document_store
|
from app.services.store import document_store
|
||||||
|
|
||||||
router = APIRouter(tags=["documents"])
|
router = APIRouter(tags=["documents"])
|
||||||
logger = logging.getLogger(__name__)
|
logger = logs.get_logger(__name__)
|
||||||
|
|
||||||
|
|
||||||
class ExportRemoteRequest(BaseModel):
|
class ExportRemoteRequest(BaseModel):
|
||||||
@@ -71,7 +71,15 @@ async def export_remote_document(document_id: str, body: ExportRemoteRequest | N
|
|||||||
|
|
||||||
ctx = d.get("remote_context")
|
ctx = d.get("remote_context")
|
||||||
if not ctx or not ctx.get("upload_url"):
|
if not ctx or not ctx.get("upload_url"):
|
||||||
print(f"[export-remote] FAILING with 400: ctx={ctx}", flush=True)
|
# The context is worth seeing when this fails, but it holds the bearer
|
||||||
|
# token used at the upload below — logging it whole put a live
|
||||||
|
# credential in plaintext on every misconfigured export.
|
||||||
|
logs.warn(
|
||||||
|
logger,
|
||||||
|
"export_remote_missing_context",
|
||||||
|
document_id=document_id,
|
||||||
|
context=logs.redact_mapping(ctx),
|
||||||
|
)
|
||||||
raise HTTPException(
|
raise HTTPException(
|
||||||
status_code=400,
|
status_code=400,
|
||||||
detail="Document does not have a registered remote upload context.",
|
detail="Document does not have a registered remote upload context.",
|
||||||
@@ -104,14 +112,26 @@ async def export_remote_document(document_id: str, body: ExportRemoteRequest | N
|
|||||||
data["file_id"] = str(ctx["resource_id"])
|
data["file_id"] = str(ctx["resource_id"])
|
||||||
|
|
||||||
upload_url = ctx["upload_url"]
|
upload_url = ctx["upload_url"]
|
||||||
print(f"[export-remote] POST {upload_url} | file_id={data.get('file_id')} | filename={filename} | size={len(bytes_data)}", flush=True)
|
logs.info(
|
||||||
|
logger,
|
||||||
|
"export_remote_upload_start",
|
||||||
|
document_id=document_id,
|
||||||
|
file_id=data.get("file_id"),
|
||||||
|
filename=filename,
|
||||||
|
size_bytes=len(bytes_data),
|
||||||
|
)
|
||||||
|
|
||||||
files = {"upload": (filename, bytes_data, "application/pdf")}
|
files = {"upload": (filename, bytes_data, "application/pdf")}
|
||||||
|
|
||||||
async with httpx.AsyncClient(timeout=120.0, follow_redirects=True) as client:
|
async with httpx.AsyncClient(timeout=120.0, follow_redirects=True) as client:
|
||||||
res = await client.post(upload_url, headers=headers, data=data, files=files)
|
res = await client.post(upload_url, headers=headers, data=data, files=files)
|
||||||
|
|
||||||
print(f"[export-remote] Response status={res.status_code} body={res.text[:500]}", flush=True)
|
logs.info(
|
||||||
|
logger,
|
||||||
|
"export_remote_upload_done",
|
||||||
|
document_id=document_id,
|
||||||
|
upstream_status=res.status_code,
|
||||||
|
)
|
||||||
|
|
||||||
if res.status_code not in (200, 201):
|
if res.status_code not in (200, 201):
|
||||||
logger.error("[export-remote] upstream %s: %s", res.status_code, res.text[:500])
|
logger.error("[export-remote] upstream %s: %s", res.status_code, res.text[:500])
|
||||||
|
|||||||
@@ -24,6 +24,10 @@ from contextlib import contextmanager
|
|||||||
from contextvars import ContextVar
|
from contextvars import ContextVar
|
||||||
from dataclasses import dataclass
|
from dataclasses import dataclass
|
||||||
|
|
||||||
|
from app.services import logs
|
||||||
|
|
||||||
|
logger = logs.get_logger(__name__)
|
||||||
|
|
||||||
|
|
||||||
class ConversionCancelled(RuntimeError):
|
class ConversionCancelled(RuntimeError):
|
||||||
"""Raised when the caller cancelled the conversion."""
|
"""Raised when the caller cancelled the conversion."""
|
||||||
@@ -37,6 +41,36 @@ CancelToken = Callable[[], bool]
|
|||||||
|
|
||||||
_cancel_check: ContextVar[CancelToken | None] = ContextVar("convert_cancel_check", default=None)
|
_cancel_check: ContextVar[CancelToken | None] = ContextVar("convert_cancel_check", default=None)
|
||||||
_deadline: ContextVar[Deadline | None] = ContextVar("convert_deadline", default=None)
|
_deadline: ContextVar[Deadline | None] = ContextVar("convert_deadline", default=None)
|
||||||
|
# Whether this conversion has already reported a broken cancel token. The check
|
||||||
|
# runs at every page boundary, so an unguarded log would produce one line per
|
||||||
|
# page for a single underlying fault.
|
||||||
|
_cancel_fault_reported: ContextVar[bool] = ContextVar(
|
||||||
|
"convert_cancel_fault_reported", default=False
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def _ask_cancel_token(fn: CancelToken) -> bool:
|
||||||
|
"""Ask the caller's token whether to stop, surviving a token that raises.
|
||||||
|
|
||||||
|
Treating a raising token as "not cancelled" is the only safe answer — the
|
||||||
|
alternative is aborting work nobody asked to abort — but doing it silently
|
||||||
|
meant a broken token made every job **quietly uncancellable**, with no
|
||||||
|
trace anywhere. The answer is unchanged; the silence is not.
|
||||||
|
"""
|
||||||
|
try:
|
||||||
|
return bool(fn())
|
||||||
|
except Exception as exc:
|
||||||
|
if not _cancel_fault_reported.get():
|
||||||
|
_cancel_fault_reported.set(True)
|
||||||
|
logs.error(
|
||||||
|
logger,
|
||||||
|
"cancel_token_failed",
|
||||||
|
error=type(exc).__name__,
|
||||||
|
detail=str(exc)[:200],
|
||||||
|
consequence="job cannot be cancelled",
|
||||||
|
exc_info=True,
|
||||||
|
)
|
||||||
|
return False
|
||||||
|
|
||||||
|
|
||||||
@dataclass
|
@dataclass
|
||||||
@@ -70,11 +104,13 @@ def conversion_scope(
|
|||||||
"""Bind a cancel token and/or deadline for the duration of one conversion."""
|
"""Bind a cancel token and/or deadline for the duration of one conversion."""
|
||||||
cancel_reset = _cancel_check.set(cancel_check)
|
cancel_reset = _cancel_check.set(cancel_check)
|
||||||
deadline_reset = _deadline.set(Deadline.start(timeout) if timeout and timeout > 0 else None)
|
deadline_reset = _deadline.set(Deadline.start(timeout) if timeout and timeout > 0 else None)
|
||||||
|
fault_reset = _cancel_fault_reported.set(False)
|
||||||
try:
|
try:
|
||||||
yield
|
yield
|
||||||
finally:
|
finally:
|
||||||
_cancel_check.reset(cancel_reset)
|
_cancel_check.reset(cancel_reset)
|
||||||
_deadline.reset(deadline_reset)
|
_deadline.reset(deadline_reset)
|
||||||
|
_cancel_fault_reported.reset(fault_reset)
|
||||||
|
|
||||||
|
|
||||||
@contextmanager
|
@contextmanager
|
||||||
@@ -124,11 +160,7 @@ def check_cancelled(stage: str = "conversion") -> None:
|
|||||||
fn = _cancel_check.get()
|
fn = _cancel_check.get()
|
||||||
if fn is None:
|
if fn is None:
|
||||||
return
|
return
|
||||||
try:
|
if _ask_cancel_token(fn):
|
||||||
cancelled = bool(fn())
|
|
||||||
except Exception:
|
|
||||||
cancelled = False
|
|
||||||
if cancelled:
|
|
||||||
raise ConversionCancelled(f"{stage} cancelled.")
|
raise ConversionCancelled(f"{stage} cancelled.")
|
||||||
|
|
||||||
|
|
||||||
@@ -139,15 +171,8 @@ def check(stage: str = "conversion") -> None:
|
|||||||
document stops working instead of merely having its result thrown away.
|
document stops working instead of merely having its result thrown away.
|
||||||
"""
|
"""
|
||||||
fn = _cancel_check.get()
|
fn = _cancel_check.get()
|
||||||
if fn is not None:
|
if fn is not None and _ask_cancel_token(fn):
|
||||||
try:
|
raise ConversionCancelled("Job cancelled.")
|
||||||
cancelled = bool(fn())
|
|
||||||
except Exception:
|
|
||||||
cancelled = False
|
|
||||||
if cancelled:
|
|
||||||
raise ConversionCancelled("Job cancelled.")
|
|
||||||
deadline = _deadline.get()
|
deadline = _deadline.get()
|
||||||
if deadline is not None and deadline.expired:
|
if deadline is not None and deadline.expired:
|
||||||
raise ConversionDeadlineExceeded(
|
raise ConversionDeadlineExceeded(f"{stage} exceeded its {deadline.seconds:.0f}s budget")
|
||||||
f"{stage} exceeded its {deadline.seconds:.0f}s budget"
|
|
||||||
)
|
|
||||||
|
|||||||
@@ -40,14 +40,15 @@ class DocumentCache:
|
|||||||
"""Readers and extracted page text for the documents seen in one scope."""
|
"""Readers and extracted page text for the documents seen in one scope."""
|
||||||
|
|
||||||
readers: dict[str, PdfReader] = field(default_factory=dict)
|
readers: dict[str, PdfReader] = field(default_factory=dict)
|
||||||
page_text: dict[tuple[str, int], str] = field(default_factory=dict)
|
# Bounded like the other two, but by bytes rather than by page count — see
|
||||||
|
# MAX_TEXT_CACHE_BYTES below for the measurement that settled it. Evicting
|
||||||
|
# is always safe: a later ask recomputes.
|
||||||
|
page_text: OrderedDict[tuple[str, int], str] = field(default_factory=OrderedDict)
|
||||||
# Glyph boxes and vector path operators recovered from the content stream
|
# Glyph boxes and vector path operators recovered from the content stream
|
||||||
# when the C++ engine is absent. Tokenising a content stream and resolving
|
# when the C++ engine is absent. Tokenising a content stream and resolving
|
||||||
# its fonts costs about as much as extracting the page's text, and the
|
# its fonts costs about as much as extracting the page's text, and the
|
||||||
# layout pipeline, table detector and scorer all ask for the same answer.
|
# layout pipeline, table detector and scorer all ask for the same answer.
|
||||||
geometry: OrderedDict[tuple[str, int], tuple[list, list]] = field(
|
geometry: OrderedDict[tuple[str, int], tuple[list, list]] = field(default_factory=OrderedDict)
|
||||||
default_factory=OrderedDict
|
|
||||||
)
|
|
||||||
# Rendered page images keyed by (document, page, dpi). A page is rasterised
|
# Rendered page images keyed by (document, page, dpi). A page is rasterised
|
||||||
# once and reused by layout detection, OCR and image export.
|
# once and reused by layout detection, OCR and image export.
|
||||||
rasters: OrderedDict[tuple[str, int, int], bytes] = field(default_factory=OrderedDict)
|
rasters: OrderedDict[tuple[str, int, int], bytes] = field(default_factory=OrderedDict)
|
||||||
@@ -58,6 +59,14 @@ class DocumentCache:
|
|||||||
raster_hits: int = 0
|
raster_hits: int = 0
|
||||||
raster_misses: int = 0
|
raster_misses: int = 0
|
||||||
raster_bytes: int = 0
|
raster_bytes: int = 0
|
||||||
|
# Extraction failures, counted rather than cached. A non-zero value here is
|
||||||
|
# the difference between "this document has blank pages" and "we could not
|
||||||
|
# read this document", which the output alone cannot tell you.
|
||||||
|
text_failures: int = 0
|
||||||
|
geometry_failures: int = 0
|
||||||
|
last_text_error: str = ""
|
||||||
|
last_geometry_error: str = ""
|
||||||
|
text_bytes: int = 0
|
||||||
|
|
||||||
def reader_for(self, data: bytes) -> PdfReader:
|
def reader_for(self, data: bytes) -> PdfReader:
|
||||||
key = _key(data)
|
key = _key(data)
|
||||||
@@ -68,18 +77,34 @@ class DocumentCache:
|
|||||||
return reader
|
return reader
|
||||||
|
|
||||||
def text_for(self, data: bytes, index: int) -> str:
|
def text_for(self, data: bytes, index: int) -> str:
|
||||||
|
"""One page's text, extracted at most once — unless extraction failed.
|
||||||
|
|
||||||
|
A failure used to be memoised as ``""``, which is the same value a
|
||||||
|
genuinely blank page produces. Everything downstream — the OCR trigger,
|
||||||
|
the table detector, the scorer — then read that empty string, agreed
|
||||||
|
with each other, and produced a confidently blank page. A failure is
|
||||||
|
now counted and *not* cached, so a later ask can succeed and the
|
||||||
|
failure is visible in the counters instead of in the output.
|
||||||
|
"""
|
||||||
key = (_key(data), index)
|
key = (_key(data), index)
|
||||||
cached = self.page_text.get(key)
|
cached = self.page_text.get(key)
|
||||||
if cached is not None:
|
if cached is not None:
|
||||||
self.hits += 1
|
self.hits += 1
|
||||||
|
self.page_text.move_to_end(key)
|
||||||
return cached
|
return cached
|
||||||
self.misses += 1
|
self.misses += 1
|
||||||
reader = self.reader_for(data)
|
reader = self.reader_for(data)
|
||||||
try:
|
try:
|
||||||
text = reader.pages[index].extract_text() or ""
|
text = reader.pages[index].extract_text() or ""
|
||||||
except Exception:
|
except Exception as exc:
|
||||||
text = ""
|
self.text_failures += 1
|
||||||
|
self.last_text_error = f"{type(exc).__name__}: {exc}"
|
||||||
|
return ""
|
||||||
self.page_text[key] = text
|
self.page_text[key] = text
|
||||||
|
self.text_bytes += len(text)
|
||||||
|
while self.page_text and self.text_bytes > MAX_TEXT_CACHE_BYTES:
|
||||||
|
_evicted, payload = self.page_text.popitem(last=False)
|
||||||
|
self.text_bytes -= len(payload)
|
||||||
return text
|
return text
|
||||||
|
|
||||||
def geometry_for(self, data: bytes, index: int, extract) -> tuple[list, list]:
|
def geometry_for(self, data: bytes, index: int, extract) -> tuple[list, list]:
|
||||||
@@ -101,8 +126,14 @@ class DocumentCache:
|
|||||||
self.misses += 1
|
self.misses += 1
|
||||||
try:
|
try:
|
||||||
result = extract()
|
result = extract()
|
||||||
except Exception:
|
except Exception as exc:
|
||||||
result = ([], [])
|
# Not cached, for the same reason as ``text_for``: an empty glyph
|
||||||
|
# list is indistinguishable from a page that genuinely has no
|
||||||
|
# glyphs, and memoising the failure makes one transient error the
|
||||||
|
# permanent truth about that page for the rest of the conversion.
|
||||||
|
self.geometry_failures += 1
|
||||||
|
self.last_geometry_error = f"{type(exc).__name__}: {exc}"
|
||||||
|
return ([], [])
|
||||||
self.geometry[key] = result
|
self.geometry[key] = result
|
||||||
while len(self.geometry) > MAX_CACHED_GEOMETRY_PAGES:
|
while len(self.geometry) > MAX_CACHED_GEOMETRY_PAGES:
|
||||||
self.geometry.popitem(last=False)
|
self.geometry.popitem(last=False)
|
||||||
@@ -153,6 +184,19 @@ MAX_RASTER_CACHE_BYTES = 64 * 1024 * 1024
|
|||||||
# few thousand dicts, and a 126-page booklet held every one of them to the end
|
# few thousand dicts, and a 126-page booklet held every one of them to the end
|
||||||
# of the conversion. Twelve pages is far more than any stage looks back.
|
# of the conversion. Twelve pages is far more than any stage looks back.
|
||||||
MAX_CACHED_GEOMETRY_PAGES = 12
|
MAX_CACHED_GEOMETRY_PAGES = 12
|
||||||
|
# Page text is bounded by *bytes*, not by page count, and the difference is
|
||||||
|
# measurable. A 64-page ceiling looked generous and was not: header/footer
|
||||||
|
# detection samples the ends of a document, the scorer walks all of it, and the
|
||||||
|
# layout pipeline walks it again, so on a 126-page booklet a page-count window
|
||||||
|
# thrashed and re-extracted. Measured on the IRS 1040 instructions (126 pages,
|
||||||
|
# pdf→docx): 212 s with a 64-page window against 161 s with none — a 32%
|
||||||
|
# regression bought for nothing.
|
||||||
|
#
|
||||||
|
# A byte budget gets the memory guarantee without the thrash. Page text runs
|
||||||
|
# tens of kilobytes even when dense, so 16 MB holds every page of any document
|
||||||
|
# inside the 200-page input limit, while still refusing to grow without bound
|
||||||
|
# if that limit is ever raised.
|
||||||
|
MAX_TEXT_CACHE_BYTES = 16 * 1024 * 1024
|
||||||
|
|
||||||
_cache: ContextVar[DocumentCache | None] = ContextVar("convert_doc_cache", default=None)
|
_cache: ContextVar[DocumentCache | None] = ContextVar("convert_doc_cache", default=None)
|
||||||
|
|
||||||
|
|||||||
@@ -1,4 +1,11 @@
|
|||||||
"""Typed convert / validation error codes (Firecrawl anydoc-inspired taxonomy)."""
|
"""Typed convert / validation error codes (Firecrawl anydoc-inspired taxonomy).
|
||||||
|
|
||||||
|
The codes exist so a caller can act on a failure instead of parsing prose. The
|
||||||
|
first seven describe a bad *input* and were the only ones the engine had, which
|
||||||
|
meant every failure after validation — engine bug, blown deadline, cancellation,
|
||||||
|
an output that would not open — arrived as an untyped 500 with a sentence in it.
|
||||||
|
The last four close that gap, so every error the engine can produce has a name.
|
||||||
|
"""
|
||||||
|
|
||||||
from __future__ import annotations
|
from __future__ import annotations
|
||||||
|
|
||||||
@@ -6,6 +13,7 @@ from enum import Enum
|
|||||||
|
|
||||||
|
|
||||||
class ConvertErrorCode(str, Enum):
|
class ConvertErrorCode(str, Enum):
|
||||||
|
# The input is unusable, and the caller can tell why.
|
||||||
unsupported = "unsupported"
|
unsupported = "unsupported"
|
||||||
encrypted = "encrypted"
|
encrypted = "encrypted"
|
||||||
needs_ocr = "needs_ocr"
|
needs_ocr = "needs_ocr"
|
||||||
@@ -13,6 +21,14 @@ class ConvertErrorCode(str, Enum):
|
|||||||
resource_limit = "resource_limit"
|
resource_limit = "resource_limit"
|
||||||
missing_part = "missing_part"
|
missing_part = "missing_part"
|
||||||
io = "io"
|
io = "io"
|
||||||
|
# The conversion itself did not complete. The distinction matters to a
|
||||||
|
# caller deciding whether to retry: `timeout` and `internal` may succeed on
|
||||||
|
# a second attempt, `cancelled` was asked for, and `invalid_output` means
|
||||||
|
# the engine produced something it will not stand behind.
|
||||||
|
timeout = "timeout"
|
||||||
|
cancelled = "cancelled"
|
||||||
|
invalid_output = "invalid_output"
|
||||||
|
internal = "internal"
|
||||||
|
|
||||||
|
|
||||||
# Default HTTP status per code
|
# Default HTTP status per code
|
||||||
@@ -24,4 +40,17 @@ HTTP_STATUS: dict[ConvertErrorCode, int] = {
|
|||||||
ConvertErrorCode.resource_limit: 413,
|
ConvertErrorCode.resource_limit: 413,
|
||||||
ConvertErrorCode.missing_part: 400,
|
ConvertErrorCode.missing_part: 400,
|
||||||
ConvertErrorCode.io: 400,
|
ConvertErrorCode.io: 400,
|
||||||
|
ConvertErrorCode.timeout: 504,
|
||||||
|
ConvertErrorCode.cancelled: 409,
|
||||||
|
ConvertErrorCode.invalid_output: 500,
|
||||||
|
ConvertErrorCode.internal: 500,
|
||||||
}
|
}
|
||||||
|
|
||||||
|
# Codes whose cause is transient: the same request may well succeed on a retry.
|
||||||
|
# Published so a client does not have to hardcode the list.
|
||||||
|
RETRYABLE_CODES = frozenset(
|
||||||
|
{
|
||||||
|
ConvertErrorCode.timeout,
|
||||||
|
ConvertErrorCode.internal,
|
||||||
|
}
|
||||||
|
)
|
||||||
|
|||||||
@@ -37,7 +37,9 @@ import bisect
|
|||||||
import contextlib
|
import contextlib
|
||||||
import math
|
import math
|
||||||
import re
|
import re
|
||||||
|
import threading
|
||||||
import unicodedata
|
import unicodedata
|
||||||
|
from collections import OrderedDict
|
||||||
from itertools import pairwise
|
from itertools import pairwise
|
||||||
from typing import Any
|
from typing import Any
|
||||||
|
|
||||||
@@ -85,8 +87,16 @@ DEFAULT_ADVANCE_RATIO = 0.5
|
|||||||
|
|
||||||
# Built font sets, keyed by the identity of the font objects they came from.
|
# Built font sets, keyed by the identity of the font objects they came from.
|
||||||
# Bounded so a long-lived process converting many documents cannot grow it.
|
# Bounded so a long-lived process converting many documents cannot grow it.
|
||||||
|
#
|
||||||
|
# Process-global, so concurrent conversions share it, so it needs a lock: the
|
||||||
|
# eviction was a check-then-``clear()``-then-write, and one conversion reaching
|
||||||
|
# the ceiling discarded font metrics another conversion was in the middle of
|
||||||
|
# using. Wrong advance widths, no exception. An ``OrderedDict`` under the lock
|
||||||
|
# also turns the all-or-nothing ``clear()`` into ordinary LRU eviction, so a
|
||||||
|
# busy process keeps the sets it is actually using.
|
||||||
MAX_CACHED_FONT_SETS = 256
|
MAX_CACHED_FONT_SETS = 256
|
||||||
_FONT_CACHE: dict[tuple, dict] = {}
|
_FONT_CACHE: OrderedDict[tuple, dict] = OrderedDict()
|
||||||
|
_FONT_CACHE_LOCK = threading.Lock()
|
||||||
|
|
||||||
|
|
||||||
def _num(value: Any, default: float = 0.0) -> float:
|
def _num(value: Any, default: float = 0.0) -> float:
|
||||||
@@ -263,16 +273,20 @@ def _page_fonts(page: Any) -> dict:
|
|||||||
"""
|
"""
|
||||||
key = _resource_font_key(page)
|
key = _resource_font_key(page)
|
||||||
if key is not None:
|
if key is not None:
|
||||||
cached = _FONT_CACHE.get(key)
|
with _FONT_CACHE_LOCK:
|
||||||
if cached is not None:
|
cached = _FONT_CACHE.get(key)
|
||||||
return cached
|
if cached is not None:
|
||||||
|
_FONT_CACHE.move_to_end(key)
|
||||||
|
return cached
|
||||||
fonts: dict = {}
|
fonts: dict = {}
|
||||||
with contextlib.suppress(Exception):
|
with contextlib.suppress(Exception):
|
||||||
fonts.update(page._layout_mode_fonts())
|
fonts.update(page._layout_mode_fonts())
|
||||||
if key is not None:
|
if key is not None:
|
||||||
if len(_FONT_CACHE) >= MAX_CACHED_FONT_SETS:
|
with _FONT_CACHE_LOCK:
|
||||||
_FONT_CACHE.clear()
|
_FONT_CACHE[key] = fonts
|
||||||
_FONT_CACHE[key] = fonts
|
_FONT_CACHE.move_to_end(key)
|
||||||
|
while len(_FONT_CACHE) > MAX_CACHED_FONT_SETS:
|
||||||
|
_FONT_CACHE.popitem(last=False)
|
||||||
return fonts
|
return fonts
|
||||||
|
|
||||||
|
|
||||||
|
|||||||
@@ -13,18 +13,30 @@ import urllib.error
|
|||||||
import urllib.request
|
import urllib.request
|
||||||
from typing import Any
|
from typing import Any
|
||||||
|
|
||||||
|
from app.services import logs, retry
|
||||||
from app.services.convert.idm.model import BBox, Block, BlockType, TextSpan
|
from app.services.convert.idm.model import BBox, Block, BlockType, TextSpan
|
||||||
|
|
||||||
|
logger = logs.get_logger(__name__)
|
||||||
|
|
||||||
|
|
||||||
|
def _retry_after_hint(exc: BaseException) -> float | None:
|
||||||
|
"""Honour a 429/503's ``Retry-After`` rather than guessing at the delay."""
|
||||||
|
if isinstance(exc, urllib.error.HTTPError):
|
||||||
|
try:
|
||||||
|
return retry.retry_after_seconds(exc.headers.get("Retry-After"))
|
||||||
|
except Exception:
|
||||||
|
return None
|
||||||
|
return None
|
||||||
|
|
||||||
|
|
||||||
def mistral_configured() -> bool:
|
def mistral_configured() -> bool:
|
||||||
return bool(os.environ.get("MISTRAL_API_KEY") or os.environ.get("DOCQUBE_MISTRAL_OCR_URL"))
|
return bool(os.environ.get("MISTRAL_API_KEY") or os.environ.get("DOCQUBE_MISTRAL_OCR_URL"))
|
||||||
|
|
||||||
|
|
||||||
def _endpoint() -> str:
|
def _endpoint() -> str:
|
||||||
return (
|
return (os.environ.get("DOCQUBE_MISTRAL_OCR_URL") or "https://api.mistral.ai/v1/ocr").rstrip(
|
||||||
os.environ.get("DOCQUBE_MISTRAL_OCR_URL")
|
"/"
|
||||||
or "https://api.mistral.ai/v1/ocr"
|
)
|
||||||
).rstrip("/")
|
|
||||||
|
|
||||||
|
|
||||||
def _map_payload_to_blocks(payload: dict[str, Any], start_order: int) -> list[Block]:
|
def _map_payload_to_blocks(payload: dict[str, Any], start_order: int) -> list[Block]:
|
||||||
@@ -126,17 +138,41 @@ def ocr_image_to_blocks_mistral(
|
|||||||
if key:
|
if key:
|
||||||
headers["Authorization"] = f"Bearer {key}"
|
headers["Authorization"] = f"Bearer {key}"
|
||||||
|
|
||||||
last_err: Exception | None = None
|
def _attempt() -> list[Block]:
|
||||||
for _attempt in range(2): # retries=1 → 2 attempts
|
req = urllib.request.Request(url, data=data, headers=headers, method="POST")
|
||||||
try:
|
opener = _opener or urllib.request.urlopen
|
||||||
req = urllib.request.Request(url, data=data, headers=headers, method="POST")
|
with opener(req, timeout=timeout) as resp:
|
||||||
opener = _opener or urllib.request.urlopen
|
raw = resp.read()
|
||||||
with opener(req, timeout=timeout) as resp:
|
payload = json.loads(raw.decode("utf-8"))
|
||||||
raw = resp.read()
|
return _map_payload_to_blocks(payload, start_order)
|
||||||
payload = json.loads(raw.decode("utf-8"))
|
|
||||||
return _map_payload_to_blocks(payload, start_order)
|
# The previous shape here retried every failure twice, back to back, with
|
||||||
except (urllib.error.URLError, urllib.error.HTTPError, TimeoutError, json.JSONDecodeError, OSError) as exc:
|
# no delay: a 401 was retried (it will never succeed), and a 429 was
|
||||||
last_err = exc
|
# retried *instantly* with its ``Retry-After`` ignored, which adds load to
|
||||||
continue
|
# a service that has just said it has too much. The accumulated error was
|
||||||
_ = last_err
|
# then discarded, so a total provider outage reached the caller as a page
|
||||||
return []
|
# with no text on it and nothing anywhere saying why.
|
||||||
|
try:
|
||||||
|
return retry.call_with_retry(
|
||||||
|
_attempt,
|
||||||
|
label="mistral-ocr",
|
||||||
|
retry_after=_retry_after_hint,
|
||||||
|
)
|
||||||
|
except retry.RetryExhausted as exc:
|
||||||
|
logs.error(
|
||||||
|
logger,
|
||||||
|
"mistral_ocr_unavailable",
|
||||||
|
attempts=exc.attempts,
|
||||||
|
error=type(exc.last).__name__ if exc.last else "unknown",
|
||||||
|
detail=str(exc.last)[:200] if exc.last else "",
|
||||||
|
)
|
||||||
|
return []
|
||||||
|
except Exception as exc: # classified as fatal by the policy above
|
||||||
|
logs.error(
|
||||||
|
logger,
|
||||||
|
"mistral_ocr_failed",
|
||||||
|
error=type(exc).__name__,
|
||||||
|
detail=str(exc)[:200],
|
||||||
|
retryable=False,
|
||||||
|
)
|
||||||
|
return []
|
||||||
|
|||||||
@@ -688,13 +688,20 @@ def enrich_scanned_pages(document: Document, pdf_bytes: bytes) -> None:
|
|||||||
order = max((b.reading_order for b in out), default=-1) + 1
|
order = max((b.reading_order for b in out), default=-1) + 1
|
||||||
return out
|
return out
|
||||||
|
|
||||||
|
# Why recognition produced nothing, when it produced nothing. Both
|
||||||
|
# engines used to collapse every failure to an empty list, so a crash,
|
||||||
|
# a blown page timeout and a genuinely blank page were indistinguishable
|
||||||
|
# downstream and in the warning the customer eventually read.
|
||||||
|
ocr_failure: str = ""
|
||||||
|
|
||||||
if mistral_hook.mistral_configured() and get_options().ocr_engine != OcrEngineChoice.rapid:
|
if mistral_hook.mistral_configured() and get_options().ocr_engine != OcrEngineChoice.rapid:
|
||||||
try:
|
try:
|
||||||
blocks = run_with_timeout(
|
blocks = run_with_timeout(
|
||||||
_run_mistral, page_timeout, label=f"Mistral OCR page {page.index + 1}"
|
_run_mistral, page_timeout, label=f"Mistral OCR page {page.index + 1}"
|
||||||
)
|
)
|
||||||
except Exception:
|
except Exception as exc:
|
||||||
blocks = []
|
blocks = []
|
||||||
|
ocr_failure = f"Mistral OCR {type(exc).__name__}: {exc}"
|
||||||
if blocks:
|
if blocks:
|
||||||
document.warnings.append(
|
document.warnings.append(
|
||||||
f"Page {page.index + 1}: OCR via Mistral product feature."
|
f"Page {page.index + 1}: OCR via Mistral product feature."
|
||||||
@@ -713,9 +720,11 @@ def enrich_scanned_pages(document: Document, pdf_bytes: bytes) -> None:
|
|||||||
blocks = run_with_timeout(
|
blocks = run_with_timeout(
|
||||||
_run_rapid, page_timeout, label=f"RapidOCR page {page.index + 1}"
|
_run_rapid, page_timeout, label=f"RapidOCR page {page.index + 1}"
|
||||||
)
|
)
|
||||||
except Exception:
|
except Exception as exc:
|
||||||
blocks = []
|
blocks = []
|
||||||
|
ocr_failure = f"RapidOCR {type(exc).__name__}: {exc}"
|
||||||
if blocks:
|
if blocks:
|
||||||
|
ocr_failure = ""
|
||||||
ar_used = False
|
ar_used = False
|
||||||
try:
|
try:
|
||||||
from app.services import ocr as ocr_service
|
from app.services import ocr as ocr_service
|
||||||
@@ -760,6 +769,7 @@ def enrich_scanned_pages(document: Document, pdf_bytes: bytes) -> None:
|
|||||||
)
|
)
|
||||||
document.warnings.append(
|
document.warnings.append(
|
||||||
f"Page {page.index + 1}: no OCR text; embedded page image."
|
f"Page {page.index + 1}: no OCR text; embedded page image."
|
||||||
|
+ (f" Recognition failed — {ocr_failure}." if ocr_failure else "")
|
||||||
)
|
)
|
||||||
continue
|
continue
|
||||||
|
|
||||||
|
|||||||
@@ -2,12 +2,16 @@
|
|||||||
|
|
||||||
from __future__ import annotations
|
from __future__ import annotations
|
||||||
|
|
||||||
|
import os
|
||||||
|
import time
|
||||||
from collections.abc import Callable
|
from collections.abc import Callable
|
||||||
from pathlib import Path
|
from pathlib import Path
|
||||||
|
|
||||||
from app.schemas.convert import Fidelity
|
from app.schemas.convert import Fidelity
|
||||||
|
from app.services import logs
|
||||||
from app.services.convert.cancellation import ConversionCancelled, conversion_scope
|
from app.services.convert.cancellation import ConversionCancelled, conversion_scope
|
||||||
from app.services.convert.doc_cache import document_cache_scope
|
from app.services.convert.doc_cache import document_cache_scope
|
||||||
|
from app.services.convert.errors import HTTP_STATUS, RETRYABLE_CODES, ConvertErrorCode
|
||||||
from app.services.convert.options import ConvertOptions, options_scope
|
from app.services.convert.options import ConvertOptions, options_scope
|
||||||
from app.services.convert.registry import registry
|
from app.services.convert.registry import registry
|
||||||
from app.services.convert.validate import (
|
from app.services.convert.validate import (
|
||||||
@@ -16,14 +20,62 @@ from app.services.convert.validate import (
|
|||||||
media_type_for,
|
media_type_for,
|
||||||
validate_input,
|
validate_input,
|
||||||
)
|
)
|
||||||
|
from app.services.convert.validation import assert_valid_pdf
|
||||||
|
|
||||||
DEFAULT_TIMEOUT_SECONDS = 120
|
logger = logs.get_logger(__name__)
|
||||||
|
|
||||||
|
# The wall-clock a whole conversion may take. This constant existed and was
|
||||||
|
# never referenced: ``conversion_scope`` was entered with ``timeout=None``, so
|
||||||
|
# only the PDF→IDM path budgeted itself and every other converter — docx→pdf,
|
||||||
|
# html→pdf, pptx→pdf — ran unbounded, holding its worker until it finished or
|
||||||
|
# the process died. It is now the default deadline for every conversion.
|
||||||
|
DEFAULT_TIMEOUT_SECONDS = 120.0
|
||||||
|
# Ceiling on the override, so a misconfigured deployment cannot disable the
|
||||||
|
# deadline by setting a very large one.
|
||||||
|
MAX_TIMEOUT_SECONDS = 1800.0
|
||||||
|
|
||||||
|
|
||||||
|
def conversion_timeout_seconds() -> float:
|
||||||
|
"""The whole-conversion deadline, from the environment, bounded."""
|
||||||
|
raw = (os.environ.get("CONVERT_TIMEOUT_SECONDS") or "").strip()
|
||||||
|
try:
|
||||||
|
value = float(raw) if raw else DEFAULT_TIMEOUT_SECONDS
|
||||||
|
except ValueError:
|
||||||
|
value = DEFAULT_TIMEOUT_SECONDS
|
||||||
|
if value <= 0:
|
||||||
|
return DEFAULT_TIMEOUT_SECONDS
|
||||||
|
return min(value, MAX_TIMEOUT_SECONDS)
|
||||||
|
|
||||||
|
|
||||||
class ConversionError(RuntimeError):
|
class ConversionError(RuntimeError):
|
||||||
def __init__(self, message: str, status_code: int = 500):
|
"""A conversion that did not complete, with a code the caller can act on.
|
||||||
|
|
||||||
|
The code used to be absent entirely, so every post-validation failure
|
||||||
|
reached the client as an untyped 500 and the job store's
|
||||||
|
``getattr(exc, "code", None)`` could never fire. A caller could not tell a
|
||||||
|
blown deadline from an engine bug, which is the difference between "retry
|
||||||
|
this" and "do not".
|
||||||
|
"""
|
||||||
|
|
||||||
|
def __init__(
|
||||||
|
self,
|
||||||
|
message: str,
|
||||||
|
status_code: int = 500,
|
||||||
|
*,
|
||||||
|
code: ConvertErrorCode = ConvertErrorCode.internal,
|
||||||
|
):
|
||||||
super().__init__(message)
|
super().__init__(message)
|
||||||
self.status_code = status_code
|
self.status_code = status_code
|
||||||
|
self.code = code
|
||||||
|
|
||||||
|
def to_detail(self) -> dict[str, object]:
|
||||||
|
"""The structured body a client should receive, matching ValidationError."""
|
||||||
|
return {
|
||||||
|
"error": str(self),
|
||||||
|
"code": self.code.value,
|
||||||
|
"status": self.status_code,
|
||||||
|
"retryable": self.code in RETRYABLE_CODES,
|
||||||
|
}
|
||||||
|
|
||||||
|
|
||||||
def _resolve_options(
|
def _resolve_options(
|
||||||
@@ -74,20 +126,39 @@ def run_conversion(
|
|||||||
source = "jpeg"
|
source = "jpeg"
|
||||||
|
|
||||||
if cancel_check and cancel_check():
|
if cancel_check and cancel_check():
|
||||||
raise ConversionError("Job cancelled.", status_code=409)
|
raise ConversionError(
|
||||||
|
"Job cancelled.", status_code=409, code=ConvertErrorCode.cancelled
|
||||||
|
)
|
||||||
|
|
||||||
plugin = registry.get(source, target)
|
plugin = registry.get(source, target)
|
||||||
if plugin is None:
|
if plugin is None:
|
||||||
raise ConversionError(f"Conversion {source}->{target} is not supported.", status_code=422)
|
raise ConversionError(
|
||||||
|
f"Conversion {source}->{target} is not supported.",
|
||||||
|
status_code=422,
|
||||||
|
code=ConvertErrorCode.unsupported,
|
||||||
|
)
|
||||||
|
|
||||||
validated = validate_input(data, filename, source)
|
validated = validate_input(data, filename, source)
|
||||||
if len(validated.data) > plugin.max_bytes:
|
if len(validated.data) > plugin.max_bytes:
|
||||||
raise ConversionError("File exceeds converter size limit.", status_code=400)
|
raise ConversionError(
|
||||||
|
"File exceeds converter size limit.",
|
||||||
|
status_code=HTTP_STATUS[ConvertErrorCode.resource_limit],
|
||||||
|
code=ConvertErrorCode.resource_limit,
|
||||||
|
)
|
||||||
|
|
||||||
from app.services.convert.result_cache import result_cache
|
from app.services.convert.result_cache import result_cache
|
||||||
|
|
||||||
effective: ConvertOptions | None = None
|
effective: ConvertOptions | None = None
|
||||||
resolution_mode = "auto" if options is None else "explicit"
|
resolution_mode = "auto" if options is None else "explicit"
|
||||||
|
started = time.monotonic()
|
||||||
|
logs.info(
|
||||||
|
logger,
|
||||||
|
"convert_start",
|
||||||
|
source=source,
|
||||||
|
target=target,
|
||||||
|
filename=filename,
|
||||||
|
size_bytes=len(validated.data),
|
||||||
|
)
|
||||||
try:
|
try:
|
||||||
from app.services.convert import auto_policy
|
from app.services.convert import auto_policy
|
||||||
|
|
||||||
@@ -97,7 +168,9 @@ def run_conversion(
|
|||||||
# decision scope clears any decision a previous job on this worker
|
# decision scope clears any decision a previous job on this worker
|
||||||
# thread left behind, so an explicit conversion can never inherit one.
|
# thread left behind, so an explicit conversion can never inherit one.
|
||||||
with (
|
with (
|
||||||
conversion_scope(cancel_check=cancel_check, timeout=None),
|
conversion_scope(
|
||||||
|
cancel_check=cancel_check, timeout=conversion_timeout_seconds()
|
||||||
|
),
|
||||||
document_cache_scope(),
|
document_cache_scope(),
|
||||||
auto_policy.decision_scope(),
|
auto_policy.decision_scope(),
|
||||||
):
|
):
|
||||||
@@ -137,14 +210,43 @@ def run_conversion(
|
|||||||
except ValidationError:
|
except ValidationError:
|
||||||
raise
|
raise
|
||||||
except ConversionCancelled as exc:
|
except ConversionCancelled as exc:
|
||||||
raise ConversionError("Job cancelled.", status_code=409) from exc
|
logs.info(logger, "convert_cancelled", source=source, target=target)
|
||||||
|
raise ConversionError(
|
||||||
|
"Job cancelled.", status_code=409, code=ConvertErrorCode.cancelled
|
||||||
|
) from exc
|
||||||
except TimeoutError as exc:
|
except TimeoutError as exc:
|
||||||
# Covers ConversionDeadlineExceeded, which subclasses TimeoutError.
|
# Covers ConversionDeadlineExceeded, which subclasses TimeoutError.
|
||||||
raise ConversionError(str(exc), status_code=504) from exc
|
logs.warn(
|
||||||
|
logger,
|
||||||
|
"convert_timeout",
|
||||||
|
source=source,
|
||||||
|
target=target,
|
||||||
|
elapsed_s=round(time.monotonic() - started, 2),
|
||||||
|
budget_s=conversion_timeout_seconds(),
|
||||||
|
)
|
||||||
|
raise ConversionError(
|
||||||
|
str(exc), status_code=504, code=ConvertErrorCode.timeout
|
||||||
|
) from exc
|
||||||
except Exception as exc:
|
except Exception as exc:
|
||||||
if "cancelled" in str(exc).lower():
|
# Cancellation used to be recognised by searching the message for the
|
||||||
raise ConversionError("Job cancelled.", status_code=409) from exc
|
# word "cancelled", so a genuine failure whose text happened to contain
|
||||||
raise ConversionError(f"Conversion failed: {exc}", status_code=500) from exc
|
# it was reported to the caller as a 409 the caller never asked for.
|
||||||
|
# Cancellation has a type; it is caught above, and nothing else here is
|
||||||
|
# a cancellation.
|
||||||
|
logs.error(
|
||||||
|
logger,
|
||||||
|
"convert_failed",
|
||||||
|
source=source,
|
||||||
|
target=target,
|
||||||
|
filename=filename,
|
||||||
|
error=type(exc).__name__,
|
||||||
|
detail=str(exc)[:300],
|
||||||
|
elapsed_s=round(time.monotonic() - started, 2),
|
||||||
|
exc_info=True,
|
||||||
|
)
|
||||||
|
raise ConversionError(
|
||||||
|
f"Conversion failed: {exc}", status_code=500, code=ConvertErrorCode.internal
|
||||||
|
) from exc
|
||||||
|
|
||||||
if len(result) == 5:
|
if len(result) == 5:
|
||||||
out_bytes, fidelity, warnings, media, quality_score = result
|
out_bytes, fidelity, warnings, media, quality_score = result
|
||||||
@@ -153,7 +255,47 @@ def run_conversion(
|
|||||||
quality_score = None
|
quality_score = None
|
||||||
|
|
||||||
if not out_bytes:
|
if not out_bytes:
|
||||||
raise ConversionError("Converter produced empty output.", status_code=500)
|
raise ConversionError(
|
||||||
|
"Converter produced empty output.",
|
||||||
|
status_code=500,
|
||||||
|
code=ConvertErrorCode.invalid_output,
|
||||||
|
)
|
||||||
|
|
||||||
|
# An output that will not open is a failure, and it must be reported as one
|
||||||
|
# here rather than discovered by the customer. ``assert_valid_pdf`` existed
|
||||||
|
# for exactly this and was called only from tests, so every PDF-target
|
||||||
|
# converter shipped bytes nothing had checked. OOXML targets already gate
|
||||||
|
# on ``assert_valid_ooxml`` inside their converters; this closes the PDF
|
||||||
|
# side, and does it once for every plugin rather than per plugin.
|
||||||
|
if target == "pdf" and (media or "").startswith("application/pdf"):
|
||||||
|
try:
|
||||||
|
assert_valid_pdf(out_bytes, min_pages=1)
|
||||||
|
except Exception as exc:
|
||||||
|
logs.error(
|
||||||
|
logger,
|
||||||
|
"convert_invalid_output",
|
||||||
|
source=source,
|
||||||
|
target=target,
|
||||||
|
error=type(exc).__name__,
|
||||||
|
detail=str(exc)[:300],
|
||||||
|
)
|
||||||
|
raise ConversionError(
|
||||||
|
f"Converter produced a PDF that could not be re-opened: {exc}",
|
||||||
|
status_code=500,
|
||||||
|
code=ConvertErrorCode.invalid_output,
|
||||||
|
) from exc
|
||||||
|
|
||||||
|
logs.info(
|
||||||
|
logger,
|
||||||
|
"convert_done",
|
||||||
|
source=source,
|
||||||
|
target=target,
|
||||||
|
elapsed_s=round(time.monotonic() - started, 2),
|
||||||
|
out_bytes=len(out_bytes),
|
||||||
|
fidelity=getattr(fidelity, "value", str(fidelity)),
|
||||||
|
warnings=len(warnings),
|
||||||
|
quality=quality_score,
|
||||||
|
)
|
||||||
|
|
||||||
if validated.permission_restricted:
|
if validated.permission_restricted:
|
||||||
warnings = [
|
warnings = [
|
||||||
|
|||||||
@@ -146,12 +146,21 @@ def _check_zip_bomb(data: bytes, *, depth: int = 0) -> None:
|
|||||||
if info.filename.lower().endswith(".zip") and not info.is_dir():
|
if info.filename.lower().endswith(".zip") and not info.is_dir():
|
||||||
try:
|
try:
|
||||||
nested = zf.read(info.filename)
|
nested = zf.read(info.filename)
|
||||||
if nested[:2] == b"PK":
|
|
||||||
_check_zip_bomb(nested, depth=depth + 1)
|
|
||||||
except ValidationError:
|
except ValidationError:
|
||||||
raise
|
raise
|
||||||
except Exception:
|
except Exception as exc:
|
||||||
pass
|
# Failing open here defeated the guard. An entry that
|
||||||
|
# cannot be read is precisely the one a crafted archive
|
||||||
|
# wants skipped, and skipping it waives the depth and
|
||||||
|
# ratio checks for everything inside it. An embedded
|
||||||
|
# archive we cannot inspect is refused instead.
|
||||||
|
raise ValidationError(
|
||||||
|
"Archive contains a nested archive that could not be "
|
||||||
|
f"inspected ({type(exc).__name__}); refused.",
|
||||||
|
code=ConvertErrorCode.resource_limit,
|
||||||
|
) from exc
|
||||||
|
if nested[:2] == b"PK":
|
||||||
|
_check_zip_bomb(nested, depth=depth + 1)
|
||||||
except zipfile.BadZipFile as exc:
|
except zipfile.BadZipFile as exc:
|
||||||
raise ValidationError(
|
raise ValidationError(
|
||||||
f"Corrupt ZIP archive: {exc}",
|
f"Corrupt ZIP archive: {exc}",
|
||||||
|
|||||||
@@ -4,12 +4,17 @@ from __future__ import annotations
|
|||||||
|
|
||||||
import contextvars
|
import contextvars
|
||||||
import os
|
import os
|
||||||
|
import threading
|
||||||
import zipfile
|
import zipfile
|
||||||
from collections.abc import Callable
|
from collections.abc import Callable
|
||||||
from concurrent.futures import ThreadPoolExecutor
|
from concurrent.futures import ThreadPoolExecutor
|
||||||
from concurrent.futures import TimeoutError as FuturesTimeout
|
from concurrent.futures import TimeoutError as FuturesTimeout
|
||||||
from typing import TypeVar
|
from typing import TypeVar
|
||||||
|
|
||||||
|
from app.services import logs
|
||||||
|
|
||||||
|
logger = logs.get_logger(__name__)
|
||||||
|
|
||||||
T = TypeVar("T")
|
T = TypeVar("T")
|
||||||
|
|
||||||
|
|
||||||
@@ -27,6 +32,87 @@ def ocr_page_timeout_seconds(default: float = 30.0) -> float:
|
|||||||
return default
|
return default
|
||||||
|
|
||||||
|
|
||||||
|
def _timeout_workers() -> int:
|
||||||
|
"""How many concurrent timed operations the process will run."""
|
||||||
|
try:
|
||||||
|
raw = (os.environ.get("CONVERT_TIMEOUT_WORKERS") or "").strip()
|
||||||
|
if raw:
|
||||||
|
return max(1, int(raw))
|
||||||
|
except ValueError:
|
||||||
|
pass
|
||||||
|
try:
|
||||||
|
cpus = len(os.sched_getaffinity(0))
|
||||||
|
except Exception:
|
||||||
|
cpus = os.cpu_count() or 1
|
||||||
|
# Generous relative to CPU count because these workers are mostly waiting
|
||||||
|
# on native code (PDFium, ONNX Runtime) that releases the GIL, and because
|
||||||
|
# an abandoned worker holds its slot until it finishes.
|
||||||
|
return max(8, cpus * 4)
|
||||||
|
|
||||||
|
|
||||||
|
_pool_lock = threading.Lock()
|
||||||
|
_pool: ThreadPoolExecutor | None = None
|
||||||
|
_pool_size = 0
|
||||||
|
_abandoned = 0
|
||||||
|
|
||||||
|
|
||||||
|
def _timeout_pool() -> ThreadPoolExecutor:
|
||||||
|
"""One shared pool for every timed operation in the process.
|
||||||
|
|
||||||
|
A fresh ``ThreadPoolExecutor`` per call — the previous shape — meant a
|
||||||
|
200-page OCR run built 200 pools, and each timeout left behind a live
|
||||||
|
thread that nothing counted. Threads and their working sets accumulated
|
||||||
|
for the life of the process with no ceiling and no signal.
|
||||||
|
|
||||||
|
A shared, bounded pool puts a ceiling on both. When every worker is stuck
|
||||||
|
on abandoned work a new submission simply never starts, and the caller's
|
||||||
|
own ``result(timeout=...)`` still fires on schedule — so saturation
|
||||||
|
degrades to a timeout rather than to unbounded thread growth.
|
||||||
|
"""
|
||||||
|
global _pool, _pool_size
|
||||||
|
with _pool_lock:
|
||||||
|
if _pool is None:
|
||||||
|
_pool_size = _timeout_workers()
|
||||||
|
_pool = ThreadPoolExecutor(max_workers=_pool_size, thread_name_prefix="convert-timeout")
|
||||||
|
return _pool
|
||||||
|
|
||||||
|
|
||||||
|
def _note_abandoned(fut, label: str, timeout: float) -> None:
|
||||||
|
"""Count a worker that outlived its caller, and let go of it when it ends.
|
||||||
|
|
||||||
|
Python cannot kill a thread, so the runaway work runs to completion. What
|
||||||
|
it must not do is disappear from view: a rising abandoned count is the
|
||||||
|
signal that some operation is systematically overrunning its budget.
|
||||||
|
"""
|
||||||
|
global _abandoned
|
||||||
|
with _pool_lock:
|
||||||
|
_abandoned += 1
|
||||||
|
current = _abandoned
|
||||||
|
capacity = _pool_size
|
||||||
|
|
||||||
|
def _released(_f) -> None:
|
||||||
|
global _abandoned
|
||||||
|
with _pool_lock:
|
||||||
|
_abandoned = max(0, _abandoned - 1)
|
||||||
|
|
||||||
|
fut.add_done_callback(_released)
|
||||||
|
logs.warn(
|
||||||
|
logger,
|
||||||
|
"timed_operation_abandoned",
|
||||||
|
label=label,
|
||||||
|
timeout_s=round(timeout, 1),
|
||||||
|
abandoned_workers=current,
|
||||||
|
pool_size=capacity,
|
||||||
|
saturated=bool(capacity and current >= capacity),
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def timeout_pool_stats() -> dict[str, int]:
|
||||||
|
"""Pool size and abandoned-worker count, for ops and for tests."""
|
||||||
|
with _pool_lock:
|
||||||
|
return {"workers": _pool_size, "abandoned": _abandoned}
|
||||||
|
|
||||||
|
|
||||||
def run_with_timeout(fn: Callable[[], T], timeout: float, *, label: str = "operation") -> T:
|
def run_with_timeout(fn: Callable[[], T], timeout: float, *, label: str = "operation") -> T:
|
||||||
"""Run *fn* and raise :class:`TimeoutError` if it outlasts *timeout*.
|
"""Run *fn* and raise :class:`TimeoutError` if it outlasts *timeout*.
|
||||||
|
|
||||||
@@ -41,12 +127,13 @@ def run_with_timeout(fn: Callable[[], T], timeout: float, *, label: str = "opera
|
|||||||
``TimeoutError`` is then delivered only *after* the work it was meant to
|
``TimeoutError`` is then delivered only *after* the work it was meant to
|
||||||
abort has completed — the timeout has no effect on wall-clock at all.
|
abort has completed — the timeout has no effect on wall-clock at all.
|
||||||
|
|
||||||
Here the executor is shut down without waiting, so the caller is released
|
The caller is instead released on schedule by waiting on the future rather
|
||||||
on schedule. Python cannot kill a thread, so the abandoned worker runs to
|
than on the pool. Python cannot kill a thread, so the abandoned worker runs
|
||||||
completion in the background; it is a daemon thread, so it cannot keep the
|
to completion in the background; it is counted (see :func:`_note_abandoned`)
|
||||||
interpreter alive. Work that must genuinely stop early cooperates through
|
and it runs in the process-wide pool from :func:`_timeout_pool`, so it can
|
||||||
:mod:`app.services.convert.cancellation`, which the pipeline checks at page
|
neither hide nor multiply without bound. Work that must genuinely stop
|
||||||
boundaries.
|
early cooperates through :mod:`app.services.convert.cancellation`, which
|
||||||
|
the pipeline checks at page boundaries.
|
||||||
"""
|
"""
|
||||||
if timeout <= 0:
|
if timeout <= 0:
|
||||||
return fn()
|
return fn()
|
||||||
@@ -55,16 +142,13 @@ def run_with_timeout(fn: Callable[[], T], timeout: float, *, label: str = "opera
|
|||||||
# conversion's cancel token, deadline and document cache. Copy the caller's
|
# conversion's cancel token, deadline and document cache. Copy the caller's
|
||||||
# context and run the callable inside it.
|
# context and run the callable inside it.
|
||||||
ctx = contextvars.copy_context()
|
ctx = contextvars.copy_context()
|
||||||
pool = ThreadPoolExecutor(max_workers=1, thread_name_prefix="convert-timeout")
|
pool = _timeout_pool()
|
||||||
|
fut = pool.submit(ctx.run, fn)
|
||||||
try:
|
try:
|
||||||
fut = pool.submit(ctx.run, fn)
|
return fut.result(timeout=timeout)
|
||||||
try:
|
except FuturesTimeout as exc:
|
||||||
return fut.result(timeout=timeout)
|
_note_abandoned(fut, label, timeout)
|
||||||
except FuturesTimeout as exc:
|
raise TimeoutError(f"{label} exceeded {timeout:.0f}s") from exc
|
||||||
raise TimeoutError(f"{label} exceeded {timeout:.0f}s") from exc
|
|
||||||
finally:
|
|
||||||
# wait=False is the whole point: never block on the runaway task.
|
|
||||||
pool.shutdown(wait=False, cancel_futures=True)
|
|
||||||
|
|
||||||
|
|
||||||
def is_ooxml_zip(data: bytes) -> bool:
|
def is_ooxml_zip(data: bytes) -> bool:
|
||||||
@@ -110,7 +194,9 @@ def assert_valid_pdf(data: bytes, *, min_pages: int = 1, must_contain: str | Non
|
|||||||
|
|
||||||
from pypdf import PdfReader
|
from pypdf import PdfReader
|
||||||
|
|
||||||
text = "\n".join((p.extract_text() or "") for p in PdfReader(io.BytesIO(data), strict=False).pages)
|
text = "\n".join(
|
||||||
|
(p.extract_text() or "") for p in PdfReader(io.BytesIO(data), strict=False).pages
|
||||||
|
)
|
||||||
if must_contain not in text:
|
if must_contain not in text:
|
||||||
raise ValueError(f"PDF missing expected token: {must_contain!r}")
|
raise ValueError(f"PDF missing expected token: {must_contain!r}")
|
||||||
|
|
||||||
|
|||||||
@@ -0,0 +1,243 @@
|
|||||||
|
"""Structured logging, and the correlation id that makes it useful.
|
||||||
|
|
||||||
|
The conversion engine had no logging at all: 181 broad ``except`` handlers
|
||||||
|
across ``app/services/convert/`` and not one ``logger`` reference among them.
|
||||||
|
What existed elsewhere was 41 ``print()`` calls — no level, no timestamp, no
|
||||||
|
traceback, and no way to tell which of six concurrent conversions emitted a
|
||||||
|
line. One of them printed a bearer token.
|
||||||
|
|
||||||
|
Three decisions, each made for a reason worth writing down:
|
||||||
|
|
||||||
|
**Key=value, not free prose.** ``ocr_failed page=7 stage=recognise
|
||||||
|
reason=TimeoutError`` can be grepped, counted and alerted on. "OCR failed on
|
||||||
|
page 7" cannot. JSON is available for a log shipper
|
||||||
|
(``CONVERT_LOG_FORMAT=json``); the default stays human-readable because the
|
||||||
|
usual reader is a person tailing a container.
|
||||||
|
|
||||||
|
**A correlation id bound to the work, not passed through it.** A conversion
|
||||||
|
crosses forty modules and several threads. Threading a ``job_id`` parameter
|
||||||
|
through all of them would be a large change that every future caller can
|
||||||
|
forget. A ``ContextVar`` set once at the boundary is carried automatically —
|
||||||
|
including into ``run_with_timeout``'s workers, which copy the caller's context
|
||||||
|
by design.
|
||||||
|
|
||||||
|
**Configured once, explicitly.** The stdlib's default root level is WARNING, so
|
||||||
|
the handful of ``logger.info`` calls that already existed were being discarded
|
||||||
|
at runtime. ``configure()`` is idempotent and safe to call from a test.
|
||||||
|
|
||||||
|
No new dependency: stdlib ``logging`` only.
|
||||||
|
"""
|
||||||
|
|
||||||
|
from __future__ import annotations
|
||||||
|
|
||||||
|
import contextvars
|
||||||
|
import json
|
||||||
|
import logging
|
||||||
|
import os
|
||||||
|
import sys
|
||||||
|
import time
|
||||||
|
import uuid
|
||||||
|
from collections.abc import Iterator
|
||||||
|
from contextlib import contextmanager
|
||||||
|
from typing import Any
|
||||||
|
|
||||||
|
# The id of the unit of work currently running, or "-" outside one. Read by the
|
||||||
|
# formatter, so nothing in the call chain has to carry it.
|
||||||
|
_correlation: contextvars.ContextVar[str] = contextvars.ContextVar(
|
||||||
|
"log_correlation_id", default="-"
|
||||||
|
)
|
||||||
|
|
||||||
|
# Field values that must never reach a log line, matched on the *key*. Matching
|
||||||
|
# on key rather than value is what makes this reliable: a token is only
|
||||||
|
# recognisable by the name of the thing holding it.
|
||||||
|
_REDACTED_KEYS = frozenset(
|
||||||
|
{
|
||||||
|
"auth_token",
|
||||||
|
"authorization",
|
||||||
|
"api_key",
|
||||||
|
"apikey",
|
||||||
|
"password",
|
||||||
|
"secret",
|
||||||
|
"token",
|
||||||
|
"fresh_token",
|
||||||
|
"cookie",
|
||||||
|
"x-csrf-token",
|
||||||
|
"csrf_token",
|
||||||
|
"bearer",
|
||||||
|
}
|
||||||
|
)
|
||||||
|
|
||||||
|
REDACTED = "***"
|
||||||
|
|
||||||
|
_configured = False
|
||||||
|
|
||||||
|
|
||||||
|
def correlation_id() -> str:
|
||||||
|
"""The id of the work in flight, for a caller that wants to echo it."""
|
||||||
|
return _correlation.get()
|
||||||
|
|
||||||
|
|
||||||
|
@contextmanager
|
||||||
|
def correlation_scope(value: str | None = None) -> Iterator[str]:
|
||||||
|
"""Bind a correlation id for the duration of one unit of work.
|
||||||
|
|
||||||
|
Resets on exit rather than overwriting, so a pooled worker thread cannot
|
||||||
|
leak one job's id into the next job that lands on it.
|
||||||
|
"""
|
||||||
|
ident = value or uuid.uuid4().hex[:12]
|
||||||
|
token = _correlation.set(ident)
|
||||||
|
try:
|
||||||
|
yield ident
|
||||||
|
finally:
|
||||||
|
_correlation.reset(token)
|
||||||
|
|
||||||
|
|
||||||
|
def redact(key: str, value: Any) -> Any:
|
||||||
|
"""Blank a value whose *key* names a secret."""
|
||||||
|
return REDACTED if key.strip().lower() in _REDACTED_KEYS else value
|
||||||
|
|
||||||
|
|
||||||
|
def redact_mapping(data: Any) -> Any:
|
||||||
|
"""Recursively redact a mapping before it is logged.
|
||||||
|
|
||||||
|
Used for context dictionaries that are useful to see but hold credentials
|
||||||
|
among their fields — logging the whole dict is how the token leak happened.
|
||||||
|
"""
|
||||||
|
if isinstance(data, dict):
|
||||||
|
return {
|
||||||
|
k: (REDACTED if str(k).strip().lower() in _REDACTED_KEYS else redact_mapping(v))
|
||||||
|
for k, v in data.items()
|
||||||
|
}
|
||||||
|
if isinstance(data, (list, tuple)):
|
||||||
|
return [redact_mapping(v) for v in data]
|
||||||
|
return data
|
||||||
|
|
||||||
|
|
||||||
|
def _render_value(value: Any) -> str:
|
||||||
|
"""One field, rendered so a grep for ``key=value`` finds it."""
|
||||||
|
if value is None:
|
||||||
|
return "-"
|
||||||
|
if isinstance(value, bool):
|
||||||
|
return "true" if value else "false"
|
||||||
|
if isinstance(value, float):
|
||||||
|
return f"{value:.3f}"
|
||||||
|
text = str(value)
|
||||||
|
if not text:
|
||||||
|
return '""'
|
||||||
|
if any(c.isspace() or c == '"' for c in text):
|
||||||
|
return json.dumps(text)
|
||||||
|
return text
|
||||||
|
|
||||||
|
|
||||||
|
class _KeyValueFormatter(logging.Formatter):
|
||||||
|
"""``ts level logger cid=… event field=value`` — one line, greppable."""
|
||||||
|
|
||||||
|
def format(self, record: logging.LogRecord) -> str:
|
||||||
|
base = (
|
||||||
|
f"{self.formatTime(record, '%Y-%m-%dT%H:%M:%S')} "
|
||||||
|
f"{record.levelname:<7} {record.name} "
|
||||||
|
f"cid={getattr(record, 'correlation_id', '-')} "
|
||||||
|
f"{record.getMessage()}"
|
||||||
|
)
|
||||||
|
fields = getattr(record, "fields", None)
|
||||||
|
if fields:
|
||||||
|
base += " " + " ".join(f"{k}={_render_value(redact(k, v))}" for k, v in fields.items())
|
||||||
|
if record.exc_info:
|
||||||
|
base += "\n" + self.formatException(record.exc_info)
|
||||||
|
return base
|
||||||
|
|
||||||
|
|
||||||
|
class _JsonFormatter(logging.Formatter):
|
||||||
|
"""One JSON object per line, for a log shipper."""
|
||||||
|
|
||||||
|
def format(self, record: logging.LogRecord) -> str:
|
||||||
|
payload: dict[str, Any] = {
|
||||||
|
"ts": time.strftime("%Y-%m-%dT%H:%M:%S", time.gmtime(record.created)),
|
||||||
|
"level": record.levelname,
|
||||||
|
"logger": record.name,
|
||||||
|
"cid": getattr(record, "correlation_id", "-"),
|
||||||
|
"event": record.getMessage(),
|
||||||
|
}
|
||||||
|
for key, value in (getattr(record, "fields", None) or {}).items():
|
||||||
|
payload[key] = redact(key, value)
|
||||||
|
if record.exc_info:
|
||||||
|
payload["exception"] = self.formatException(record.exc_info)
|
||||||
|
return json.dumps(payload, default=str)
|
||||||
|
|
||||||
|
|
||||||
|
class _CorrelationFilter(logging.Filter):
|
||||||
|
"""Stamp every record with the id of the work that produced it."""
|
||||||
|
|
||||||
|
def filter(self, record: logging.LogRecord) -> bool:
|
||||||
|
record.correlation_id = _correlation.get()
|
||||||
|
return True
|
||||||
|
|
||||||
|
|
||||||
|
def configure(force: bool = False) -> None:
|
||||||
|
"""Install the handler and level. Idempotent.
|
||||||
|
|
||||||
|
``CONVERT_LOG_LEVEL`` (default ``INFO``) and ``CONVERT_LOG_FORMAT``
|
||||||
|
(``text`` | ``json``, default ``text``) are the only knobs. Both are read
|
||||||
|
from the environment, never hardcoded per deployment.
|
||||||
|
"""
|
||||||
|
global _configured
|
||||||
|
if _configured and not force:
|
||||||
|
return
|
||||||
|
|
||||||
|
level_name = (os.environ.get("CONVERT_LOG_LEVEL") or "INFO").strip().upper()
|
||||||
|
level = getattr(logging, level_name, logging.INFO)
|
||||||
|
want_json = (os.environ.get("CONVERT_LOG_FORMAT") or "text").strip().lower() == "json"
|
||||||
|
|
||||||
|
handler = logging.StreamHandler(sys.stderr)
|
||||||
|
handler.setFormatter(_JsonFormatter() if want_json else _KeyValueFormatter())
|
||||||
|
handler.addFilter(_CorrelationFilter())
|
||||||
|
|
||||||
|
root = logging.getLogger()
|
||||||
|
# Replace only the handlers this module installed, so calling configure()
|
||||||
|
# twice does not stack duplicate output and uvicorn's own handlers survive.
|
||||||
|
for existing in list(root.handlers):
|
||||||
|
if getattr(existing, "_pdfengine", False):
|
||||||
|
root.removeHandler(existing)
|
||||||
|
handler._pdfengine = True # type: ignore[attr-defined]
|
||||||
|
root.addHandler(handler)
|
||||||
|
root.setLevel(level)
|
||||||
|
_configured = True
|
||||||
|
|
||||||
|
|
||||||
|
def get_logger(name: str) -> logging.Logger:
|
||||||
|
"""A logger that is guaranteed to have somewhere to write."""
|
||||||
|
configure()
|
||||||
|
return logging.getLogger(name)
|
||||||
|
|
||||||
|
|
||||||
|
def event(
|
||||||
|
logger: logging.Logger,
|
||||||
|
level: int,
|
||||||
|
name: str,
|
||||||
|
*,
|
||||||
|
exc_info: bool | BaseException | None = None,
|
||||||
|
**fields: Any,
|
||||||
|
) -> None:
|
||||||
|
"""Emit one structured event.
|
||||||
|
|
||||||
|
The message is a stable, greppable identifier (``ocr_page_failed``), and
|
||||||
|
everything that varies goes in *fields* — so a dashboard can count events
|
||||||
|
without parsing prose.
|
||||||
|
"""
|
||||||
|
logger.log(level, name, extra={"fields": fields}, exc_info=exc_info)
|
||||||
|
|
||||||
|
|
||||||
|
def info(logger: logging.Logger, name: str, **fields: Any) -> None:
|
||||||
|
event(logger, logging.INFO, name, **fields)
|
||||||
|
|
||||||
|
|
||||||
|
def warn(logger: logging.Logger, name: str, **fields: Any) -> None:
|
||||||
|
event(logger, logging.WARNING, name, **fields)
|
||||||
|
|
||||||
|
|
||||||
|
def error(logger: logging.Logger, name: str, *, exc_info: Any = None, **fields: Any) -> None:
|
||||||
|
event(logger, logging.ERROR, name, exc_info=exc_info, **fields)
|
||||||
|
|
||||||
|
|
||||||
|
def debug(logger: logging.Logger, name: str, **fields: Any) -> None:
|
||||||
|
event(logger, logging.DEBUG, name, **fields)
|
||||||
+153
-1
@@ -1,10 +1,13 @@
|
|||||||
import contextvars
|
import contextvars
|
||||||
|
import copy
|
||||||
|
import hashlib
|
||||||
import io
|
import io
|
||||||
import logging
|
import logging
|
||||||
import os
|
import os
|
||||||
import re
|
import re
|
||||||
import threading
|
import threading
|
||||||
import time
|
import time
|
||||||
|
from collections import OrderedDict
|
||||||
from pathlib import Path
|
from pathlib import Path
|
||||||
from typing import Any, Union
|
from typing import Any, Union
|
||||||
|
|
||||||
@@ -450,6 +453,138 @@ def _adaptive_arabic_needed(en_lines: list[dict[str, Any]]) -> bool:
|
|||||||
return mean_confidence < 0.58
|
return mean_confidence < 0.58
|
||||||
|
|
||||||
|
|
||||||
|
class _RecognitionCache:
|
||||||
|
"""Recognition results, keyed by the pixels that produced them.
|
||||||
|
|
||||||
|
Recognition is by a wide margin the most expensive thing this engine does,
|
||||||
|
and it was being paid once per *output format*. Measured on a 4-page scan
|
||||||
|
converted to five targets: OCR ran five times, 120.6 s against 34.0 s with
|
||||||
|
this cache, and the outputs were byte-identical. Nothing about the answer
|
||||||
|
depends on the target, so four of those five passes were pure waste.
|
||||||
|
|
||||||
|
Keyed by a digest of the image bytes plus the Arabic flag, because that is
|
||||||
|
the whole of the input. Bounded twice over — entry count and an estimate of
|
||||||
|
the bytes held — with LRU eviction and a TTL, so a long-lived process cannot
|
||||||
|
accumulate the results of every document it has ever seen.
|
||||||
|
|
||||||
|
Deliberately *not* the per-conversion ``doc_cache``: that scope is torn down
|
||||||
|
at the end of each conversion, which is exactly the boundary the duplicated
|
||||||
|
work was crossing.
|
||||||
|
"""
|
||||||
|
|
||||||
|
def __init__(self, max_entries: int, max_bytes: int, ttl_seconds: float) -> None:
|
||||||
|
self._entries: OrderedDict[str, tuple[float, int, dict[str, Any]]] = OrderedDict()
|
||||||
|
self._lock = threading.Lock()
|
||||||
|
self._bytes = 0
|
||||||
|
self.max_entries = max_entries
|
||||||
|
self.max_bytes = max_bytes
|
||||||
|
self.ttl_seconds = ttl_seconds
|
||||||
|
self.hits = 0
|
||||||
|
self.misses = 0
|
||||||
|
|
||||||
|
@staticmethod
|
||||||
|
def _size_of(payload: dict[str, Any]) -> int:
|
||||||
|
lines = payload.get("lines") or []
|
||||||
|
return sum(len(str(line.get("text") or "")) + 400 for line in lines) + 256
|
||||||
|
|
||||||
|
def get(self, key: str) -> dict[str, Any] | None:
|
||||||
|
now = time.time()
|
||||||
|
with self._lock:
|
||||||
|
found = self._entries.get(key)
|
||||||
|
if found is None:
|
||||||
|
self.misses += 1
|
||||||
|
return None
|
||||||
|
stored_at, size, payload = found
|
||||||
|
if now - stored_at > self.ttl_seconds:
|
||||||
|
del self._entries[key]
|
||||||
|
self._bytes -= size
|
||||||
|
self.misses += 1
|
||||||
|
return None
|
||||||
|
self._entries.move_to_end(key)
|
||||||
|
self.hits += 1
|
||||||
|
# A copy, not the stored object. Handing out the entry itself lets
|
||||||
|
# any consumer that annotates a line silently rewrite what the next
|
||||||
|
# conversion reads back.
|
||||||
|
return copy.deepcopy(payload)
|
||||||
|
|
||||||
|
def put(self, key: str, payload: dict[str, Any]) -> None:
|
||||||
|
size = self._size_of(payload)
|
||||||
|
if size > self.max_bytes:
|
||||||
|
return
|
||||||
|
with self._lock:
|
||||||
|
existing = self._entries.pop(key, None)
|
||||||
|
if existing is not None:
|
||||||
|
self._bytes -= existing[1]
|
||||||
|
self._entries[key] = (time.time(), size, copy.deepcopy(payload))
|
||||||
|
self._bytes += size
|
||||||
|
while self._entries and (
|
||||||
|
len(self._entries) > self.max_entries or self._bytes > self.max_bytes
|
||||||
|
):
|
||||||
|
_evicted, (_ts, evicted_size, _payload) = self._entries.popitem(last=False)
|
||||||
|
self._bytes -= evicted_size
|
||||||
|
|
||||||
|
def clear(self) -> None:
|
||||||
|
with self._lock:
|
||||||
|
self._entries.clear()
|
||||||
|
self._bytes = 0
|
||||||
|
|
||||||
|
def stats(self) -> dict[str, int]:
|
||||||
|
with self._lock:
|
||||||
|
return {
|
||||||
|
"entries": len(self._entries),
|
||||||
|
"bytes": self._bytes,
|
||||||
|
"hits": self.hits,
|
||||||
|
"misses": self.misses,
|
||||||
|
}
|
||||||
|
|
||||||
|
|
||||||
|
def _cache_setting(name: str, default: int) -> int:
|
||||||
|
try:
|
||||||
|
raw = (os.environ.get(name) or "").strip()
|
||||||
|
return int(raw) if raw else default
|
||||||
|
except ValueError:
|
||||||
|
return default
|
||||||
|
|
||||||
|
|
||||||
|
_recognition_cache = _RecognitionCache(
|
||||||
|
max_entries=_cache_setting("CONVERT_OCR_CACHE_ENTRIES", 256),
|
||||||
|
max_bytes=_cache_setting("CONVERT_OCR_CACHE_BYTES", 64 * 1024 * 1024),
|
||||||
|
ttl_seconds=float(_cache_setting("CONVERT_OCR_CACHE_TTL_SECONDS", 1800)),
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def ocr_cache_stats() -> dict[str, int]:
|
||||||
|
"""Hit/miss counters, for the ops endpoint and for tests."""
|
||||||
|
return _recognition_cache.stats()
|
||||||
|
|
||||||
|
|
||||||
|
def clear_ocr_cache() -> None:
|
||||||
|
"""Drop every cached recognition. Used by tests and by ops."""
|
||||||
|
_recognition_cache.clear()
|
||||||
|
|
||||||
|
|
||||||
|
def _recognition_key(image: Any, try_arabic: bool | None) -> str | None:
|
||||||
|
"""A digest of exactly the inputs recognition depends on, or None.
|
||||||
|
|
||||||
|
Returns None when the image cannot be digested cheaply, which disables
|
||||||
|
caching for that call rather than guessing at a key — a wrong key here
|
||||||
|
would return one page's text for another, which is far worse than a miss.
|
||||||
|
"""
|
||||||
|
try:
|
||||||
|
if isinstance(image, (bytes, bytearray, memoryview)):
|
||||||
|
payload = bytes(image)
|
||||||
|
else:
|
||||||
|
data = getattr(image, "tobytes", None)
|
||||||
|
if data is None:
|
||||||
|
return None
|
||||||
|
payload = repr(getattr(image, "shape", ())).encode() + data()
|
||||||
|
except Exception:
|
||||||
|
return None
|
||||||
|
digest = hashlib.blake2b(payload, digest_size=20)
|
||||||
|
digest.update(repr((try_arabic, _ocr_ar_status)).encode())
|
||||||
|
return digest.hexdigest()
|
||||||
|
|
||||||
|
|
||||||
def recognize_image(
|
def recognize_image(
|
||||||
image: Union[bytes, "Any"], *, try_arabic: bool | None = None
|
image: Union[bytes, "Any"], *, try_arabic: bool | None = None
|
||||||
) -> dict[str, Any]:
|
) -> dict[str, Any]:
|
||||||
@@ -469,6 +604,19 @@ def recognize_image(
|
|||||||
|
|
||||||
start_time = time.time()
|
start_time = time.time()
|
||||||
width, height = _image_size(image)
|
width, height = _image_size(image)
|
||||||
|
|
||||||
|
cache_key = _recognition_key(image, try_arabic)
|
||||||
|
cached = _recognition_cache.get(cache_key) if cache_key else None
|
||||||
|
if cached is not None:
|
||||||
|
# A hit must reproduce the miss exactly, side effect included: the
|
||||||
|
# caller reads the Arabic flag through a context variable straight
|
||||||
|
# after this returns, and a hit that skipped setting it reported the
|
||||||
|
# wrong provenance for the page.
|
||||||
|
_ocr_ar_used_var.set(bool(cached.get("ocrAr")))
|
||||||
|
cached["processTimeMs"] = round((time.time() - start_time) * 1000.0, 2)
|
||||||
|
cached["cached"] = True
|
||||||
|
return cached
|
||||||
|
|
||||||
ar_used = False
|
ar_used = False
|
||||||
|
|
||||||
# Keep both passes under one lock. Releasing the lock between EN and AR
|
# Keep both passes under one lock. Releasing the lock between EN and AR
|
||||||
@@ -500,13 +648,17 @@ def recognize_image(
|
|||||||
|
|
||||||
_ocr_ar_used_var.set(ar_used)
|
_ocr_ar_used_var.set(ar_used)
|
||||||
elapsed_ms = (time.time() - start_time) * 1000.0
|
elapsed_ms = (time.time() - start_time) * 1000.0
|
||||||
return {
|
payload = {
|
||||||
"imageWidth": width,
|
"imageWidth": width,
|
||||||
"imageHeight": height,
|
"imageHeight": height,
|
||||||
"lines": lines,
|
"lines": lines,
|
||||||
"processTimeMs": round(elapsed_ms, 2),
|
"processTimeMs": round(elapsed_ms, 2),
|
||||||
"ocrAr": ar_used,
|
"ocrAr": ar_used,
|
||||||
|
"cached": False,
|
||||||
}
|
}
|
||||||
|
if cache_key:
|
||||||
|
_recognition_cache.put(cache_key, payload)
|
||||||
|
return payload
|
||||||
|
|
||||||
|
|
||||||
def _image_size(image: Any) -> tuple[int, int]:
|
def _image_size(image: Any) -> tuple[int, int]:
|
||||||
|
|||||||
@@ -0,0 +1,310 @@
|
|||||||
|
"""Retrying a transient failure without making an outage worse.
|
||||||
|
|
||||||
|
The engine had exactly one retry in it, and it was the wrong shape
|
||||||
|
(``ocr/mistral_hook.py``): two attempts back to back with no sleep, catching
|
||||||
|
every ``HTTPError`` alike. That retries a 401 — which will never succeed —
|
||||||
|
and, worse, retries a **429 instantly**, adding load to a service that has just
|
||||||
|
said it has too much. It then discarded the error, so a total provider outage
|
||||||
|
looked like a document with no text on it.
|
||||||
|
|
||||||
|
Three rules, and each is here because its absence causes a specific failure:
|
||||||
|
|
||||||
|
**Classify before retrying.** A 400 or a 401 is the caller's fault and will
|
||||||
|
fail identically forever; retrying costs latency and buys nothing. A 429, a
|
||||||
|
5xx, a reset connection or a timeout may well succeed on the next attempt.
|
||||||
|
Anything not known to be retryable is treated as fatal, so a new error class
|
||||||
|
fails fast rather than being hammered.
|
||||||
|
|
||||||
|
**Back off exponentially, and jitter.** Without backoff, N clients retrying a
|
||||||
|
recovering service re-saturate it the moment it comes back. Without jitter they
|
||||||
|
do it *in lockstep* — the thundering herd — because they all failed at the same
|
||||||
|
instant and all wait the same interval. Full jitter (sleep uniformly in
|
||||||
|
``[0, computed]``) is the variant that spreads them, and it is what AWS's
|
||||||
|
architecture guidance recommends.
|
||||||
|
|
||||||
|
**Obey ``Retry-After``.** When a server states how long to wait, guessing is
|
||||||
|
strictly worse than listening.
|
||||||
|
|
||||||
|
The delay budget is capped so a retry can never outlive the caller's own
|
||||||
|
deadline, and every attempt is logged with its reason, so an outage is visible
|
||||||
|
in the logs rather than only in the output.
|
||||||
|
"""
|
||||||
|
|
||||||
|
from __future__ import annotations
|
||||||
|
|
||||||
|
import random
|
||||||
|
import time
|
||||||
|
from collections.abc import Callable
|
||||||
|
from dataclasses import dataclass
|
||||||
|
from typing import Any, TypeVar
|
||||||
|
|
||||||
|
from app.services import logs
|
||||||
|
|
||||||
|
logger = logs.get_logger(__name__)
|
||||||
|
|
||||||
|
T = TypeVar("T")
|
||||||
|
|
||||||
|
# Defaults chosen for a call already covered by a per-page timeout: the whole
|
||||||
|
# retry sequence must stay well inside it, so the ceiling is low.
|
||||||
|
DEFAULT_ATTEMPTS = 3
|
||||||
|
DEFAULT_BASE_DELAY = 0.5
|
||||||
|
DEFAULT_MAX_DELAY = 8.0
|
||||||
|
# A server-supplied Retry-After longer than this is a signal to give up rather
|
||||||
|
# than to sleep: the caller has a deadline of its own.
|
||||||
|
MAX_HONOURED_RETRY_AFTER = 30.0
|
||||||
|
|
||||||
|
# HTTP status codes worth trying again. 408 request timeout, 425 too early,
|
||||||
|
# 429 too many requests, and the 5xx family that indicates the server — not the
|
||||||
|
# request — is at fault.
|
||||||
|
RETRYABLE_STATUS = frozenset({408, 425, 429, 500, 502, 503, 504, 507, 509})
|
||||||
|
|
||||||
|
|
||||||
|
class RetryExhausted(RuntimeError):
|
||||||
|
"""Every attempt failed. Carries the last cause, which must not be lost."""
|
||||||
|
|
||||||
|
def __init__(self, label: str, attempts: int, last: BaseException | None) -> None:
|
||||||
|
super().__init__(
|
||||||
|
f"{label} failed after {attempts} attempt(s): "
|
||||||
|
f"{type(last).__name__ if last else 'unknown'}: {last}"
|
||||||
|
)
|
||||||
|
self.label = label
|
||||||
|
self.attempts = attempts
|
||||||
|
self.last = last
|
||||||
|
|
||||||
|
|
||||||
|
@dataclass(frozen=True)
|
||||||
|
class RetryPolicy:
|
||||||
|
attempts: int = DEFAULT_ATTEMPTS
|
||||||
|
base_delay: float = DEFAULT_BASE_DELAY
|
||||||
|
max_delay: float = DEFAULT_MAX_DELAY
|
||||||
|
# Total wall-clock the retry sequence may spend sleeping. Bounds the worst
|
||||||
|
# case so a retry cannot silently blow a caller's timeout.
|
||||||
|
max_total_delay: float = 12.0
|
||||||
|
|
||||||
|
|
||||||
|
def backoff_delay(
|
||||||
|
attempt: int,
|
||||||
|
*,
|
||||||
|
base: float = DEFAULT_BASE_DELAY,
|
||||||
|
cap: float = DEFAULT_MAX_DELAY,
|
||||||
|
rng: random.Random | None = None,
|
||||||
|
) -> float:
|
||||||
|
"""Full-jitter exponential backoff for a zero-based *attempt* index.
|
||||||
|
|
||||||
|
``uniform(0, min(cap, base * 2**attempt))``. Returning a *range* rather
|
||||||
|
than the exponential value itself is the point: it is what decorrelates
|
||||||
|
clients that failed simultaneously.
|
||||||
|
"""
|
||||||
|
ceiling = min(cap, base * (2.0 ** max(0, attempt)))
|
||||||
|
source = rng or random
|
||||||
|
return source.uniform(0.0, ceiling)
|
||||||
|
|
||||||
|
|
||||||
|
def retry_after_seconds(value: Any) -> float | None:
|
||||||
|
"""Parse a ``Retry-After`` header value in delta-seconds form.
|
||||||
|
|
||||||
|
The HTTP-date form is deliberately not honoured: it needs a trusted clock
|
||||||
|
on both ends, and every provider this engine talks to sends seconds.
|
||||||
|
"""
|
||||||
|
if value is None:
|
||||||
|
return None
|
||||||
|
try:
|
||||||
|
seconds = float(str(value).strip())
|
||||||
|
except (TypeError, ValueError):
|
||||||
|
return None
|
||||||
|
if seconds < 0:
|
||||||
|
return None
|
||||||
|
return min(seconds, MAX_HONOURED_RETRY_AFTER)
|
||||||
|
|
||||||
|
|
||||||
|
def status_is_retryable(status: int | None) -> bool:
|
||||||
|
return status is not None and int(status) in RETRYABLE_STATUS
|
||||||
|
|
||||||
|
|
||||||
|
def is_retryable_exception(exc: BaseException) -> bool:
|
||||||
|
"""Whether *exc* describes a transient condition.
|
||||||
|
|
||||||
|
Deliberately conservative: an unrecognised error is fatal. Retrying an
|
||||||
|
unknown failure is how a bug becomes an outage amplifier.
|
||||||
|
"""
|
||||||
|
import http.client
|
||||||
|
import socket
|
||||||
|
import urllib.error
|
||||||
|
|
||||||
|
if isinstance(exc, urllib.error.HTTPError):
|
||||||
|
return status_is_retryable(exc.code)
|
||||||
|
if isinstance(exc, urllib.error.URLError):
|
||||||
|
# DNS failure, refused connection, unreachable host — all transient
|
||||||
|
# from the caller's point of view.
|
||||||
|
return True
|
||||||
|
if isinstance(exc, (TimeoutError, socket.timeout, ConnectionError, http.client.HTTPException)):
|
||||||
|
return True
|
||||||
|
if isinstance(exc, OSError):
|
||||||
|
return True
|
||||||
|
# An httpx error, if httpx is installed, without importing it eagerly.
|
||||||
|
name = type(exc).__module__.split(".")[0]
|
||||||
|
if name == "httpx":
|
||||||
|
return type(exc).__name__ in {
|
||||||
|
"ConnectError",
|
||||||
|
"ConnectTimeout",
|
||||||
|
"ReadTimeout",
|
||||||
|
"WriteTimeout",
|
||||||
|
"PoolTimeout",
|
||||||
|
"ReadError",
|
||||||
|
"WriteError",
|
||||||
|
"RemoteProtocolError",
|
||||||
|
"TimeoutException",
|
||||||
|
}
|
||||||
|
if isinstance(exc, ValueError):
|
||||||
|
# Includes json.JSONDecodeError: a truncated response body is a
|
||||||
|
# transport symptom, not a permanent disagreement about the API.
|
||||||
|
return type(exc).__name__ == "JSONDecodeError"
|
||||||
|
return False
|
||||||
|
|
||||||
|
|
||||||
|
def _sleep_for(
|
||||||
|
attempt: int,
|
||||||
|
policy: RetryPolicy,
|
||||||
|
spent: float,
|
||||||
|
hint: float | None,
|
||||||
|
rng: random.Random | None,
|
||||||
|
) -> float:
|
||||||
|
"""How long to wait before the next attempt, respecting the total budget."""
|
||||||
|
delay = (
|
||||||
|
hint
|
||||||
|
if hint is not None
|
||||||
|
else backoff_delay(attempt, base=policy.base_delay, cap=policy.max_delay, rng=rng)
|
||||||
|
)
|
||||||
|
return max(0.0, min(delay, policy.max_total_delay - spent))
|
||||||
|
|
||||||
|
|
||||||
|
def call_with_retry(
|
||||||
|
fn: Callable[[], T],
|
||||||
|
*,
|
||||||
|
label: str,
|
||||||
|
policy: RetryPolicy | None = None,
|
||||||
|
retryable: Callable[[BaseException], bool] = is_retryable_exception,
|
||||||
|
retry_after: Callable[[BaseException], float | None] | None = None,
|
||||||
|
sleep: Callable[[float], None] = time.sleep,
|
||||||
|
rng: random.Random | None = None,
|
||||||
|
) -> T:
|
||||||
|
"""Call *fn*, retrying transient failures with backoff and jitter.
|
||||||
|
|
||||||
|
Raises :class:`RetryExhausted` carrying the final cause when every attempt
|
||||||
|
fails, and re-raises immediately on a failure classified as fatal — the
|
||||||
|
caller must be able to tell "the provider is down" from "this request is
|
||||||
|
malformed".
|
||||||
|
|
||||||
|
*sleep* and *rng* are injected so the policy can be tested without spending
|
||||||
|
the wall-clock it describes.
|
||||||
|
"""
|
||||||
|
active = policy or RetryPolicy()
|
||||||
|
last: BaseException | None = None
|
||||||
|
spent = 0.0
|
||||||
|
|
||||||
|
for attempt in range(active.attempts):
|
||||||
|
try:
|
||||||
|
return fn()
|
||||||
|
except Exception as exc:
|
||||||
|
last = exc
|
||||||
|
final = attempt >= active.attempts - 1
|
||||||
|
if not retryable(exc):
|
||||||
|
logs.warn(
|
||||||
|
logger,
|
||||||
|
"retry_fatal",
|
||||||
|
label=label,
|
||||||
|
attempt=attempt + 1,
|
||||||
|
error=type(exc).__name__,
|
||||||
|
detail=str(exc)[:200],
|
||||||
|
)
|
||||||
|
raise
|
||||||
|
if final:
|
||||||
|
break
|
||||||
|
hint = retry_after(exc) if retry_after else None
|
||||||
|
delay = _sleep_for(attempt, active, spent, hint, rng)
|
||||||
|
logs.warn(
|
||||||
|
logger,
|
||||||
|
"retry_attempt",
|
||||||
|
label=label,
|
||||||
|
attempt=attempt + 1,
|
||||||
|
of=active.attempts,
|
||||||
|
error=type(exc).__name__,
|
||||||
|
detail=str(exc)[:200],
|
||||||
|
delay_s=round(delay, 3),
|
||||||
|
honoured_retry_after=hint is not None,
|
||||||
|
)
|
||||||
|
if delay > 0:
|
||||||
|
sleep(delay)
|
||||||
|
spent += delay
|
||||||
|
|
||||||
|
logs.error(
|
||||||
|
logger,
|
||||||
|
"retry_exhausted",
|
||||||
|
label=label,
|
||||||
|
attempts=active.attempts,
|
||||||
|
error=type(last).__name__ if last else "unknown",
|
||||||
|
detail=str(last)[:200] if last else "",
|
||||||
|
)
|
||||||
|
raise RetryExhausted(label, active.attempts, last)
|
||||||
|
|
||||||
|
|
||||||
|
async def call_with_retry_async(
|
||||||
|
fn: Callable[[], Any],
|
||||||
|
*,
|
||||||
|
label: str,
|
||||||
|
policy: RetryPolicy | None = None,
|
||||||
|
retryable: Callable[[BaseException], bool] = is_retryable_exception,
|
||||||
|
retry_after: Callable[[BaseException], float | None] | None = None,
|
||||||
|
rng: random.Random | None = None,
|
||||||
|
) -> Any:
|
||||||
|
"""Async twin of :func:`call_with_retry`, for the httpx call paths."""
|
||||||
|
import asyncio
|
||||||
|
|
||||||
|
active = policy or RetryPolicy()
|
||||||
|
last: BaseException | None = None
|
||||||
|
spent = 0.0
|
||||||
|
|
||||||
|
for attempt in range(active.attempts):
|
||||||
|
try:
|
||||||
|
return await fn()
|
||||||
|
except Exception as exc:
|
||||||
|
last = exc
|
||||||
|
final = attempt >= active.attempts - 1
|
||||||
|
if not retryable(exc):
|
||||||
|
logs.warn(
|
||||||
|
logger,
|
||||||
|
"retry_fatal",
|
||||||
|
label=label,
|
||||||
|
attempt=attempt + 1,
|
||||||
|
error=type(exc).__name__,
|
||||||
|
detail=str(exc)[:200],
|
||||||
|
)
|
||||||
|
raise
|
||||||
|
if final:
|
||||||
|
break
|
||||||
|
hint = retry_after(exc) if retry_after else None
|
||||||
|
delay = _sleep_for(attempt, active, spent, hint, rng)
|
||||||
|
logs.warn(
|
||||||
|
logger,
|
||||||
|
"retry_attempt",
|
||||||
|
label=label,
|
||||||
|
attempt=attempt + 1,
|
||||||
|
of=active.attempts,
|
||||||
|
error=type(exc).__name__,
|
||||||
|
detail=str(exc)[:200],
|
||||||
|
delay_s=round(delay, 3),
|
||||||
|
honoured_retry_after=hint is not None,
|
||||||
|
)
|
||||||
|
if delay > 0:
|
||||||
|
await asyncio.sleep(delay)
|
||||||
|
spent += delay
|
||||||
|
|
||||||
|
logs.error(
|
||||||
|
logger,
|
||||||
|
"retry_exhausted",
|
||||||
|
label=label,
|
||||||
|
attempts=active.attempts,
|
||||||
|
error=type(last).__name__ if last else "unknown",
|
||||||
|
detail=str(last)[:200] if last else "",
|
||||||
|
)
|
||||||
|
raise RetryExhausted(label, active.attempts, last)
|
||||||
Binary file not shown.
@@ -0,0 +1,183 @@
|
|||||||
|
# Architecture
|
||||||
|
|
||||||
|
## What this service is
|
||||||
|
|
||||||
|
A document conversion engine behind a FastAPI gateway. You send it a file and
|
||||||
|
the format you want back; it decides everything else — whether to OCR, whether
|
||||||
|
to reflow the text or hold its position, how to treat running headers, whether
|
||||||
|
to look for tables — and returns the converted bytes.
|
||||||
|
|
||||||
|
It is **deterministic**. There is no language model anywhere in the pipeline.
|
||||||
|
The only nondeterministic component is the OCR recogniser, and it is reached
|
||||||
|
through exactly one function (`app.services.ocr.recognize_image`), which makes
|
||||||
|
the rest of the system testable without stubbing anything.
|
||||||
|
|
||||||
|
Everything it depends on is permissively licensed free software, and every
|
||||||
|
model it runs is freely redistributable. That is a hard constraint, not a
|
||||||
|
preference: see [limits.md](limits.md).
|
||||||
|
|
||||||
|
## The shape of a conversion
|
||||||
|
|
||||||
|
```
|
||||||
|
HTTP request
|
||||||
|
│
|
||||||
|
├─ admission control ......... app/services/convert/admission.py
|
||||||
|
│ refuses at capacity with 503 + Retry-After rather than accepting
|
||||||
|
│ work the process cannot do
|
||||||
|
│
|
||||||
|
├─ validation ................ app/services/convert/validate.py
|
||||||
|
│ size, page count, magic bytes vs declared type, encryption,
|
||||||
|
│ zip-bomb depth/ratio. Raises a typed ValidationError.
|
||||||
|
│
|
||||||
|
├─ routing ................... app/services/convert/auto_policy.py
|
||||||
|
│ reads the document and picks the reconstruction path
|
||||||
|
│
|
||||||
|
├─ conversion ................ app/services/convert/pipeline.py
|
||||||
|
│ enters four scopes, all ContextVar-based and all per-conversion:
|
||||||
|
│ cancellation (cancel token + wall-clock deadline)
|
||||||
|
│ document cache (readers, page text, geometry, rasters)
|
||||||
|
│ policy decision
|
||||||
|
│ options
|
||||||
|
│ then calls exactly one plugin
|
||||||
|
│
|
||||||
|
├─ output validation ......... app/services/convert/validation.py
|
||||||
|
│ PDF must re-open; OOXML must contain its mandatory part
|
||||||
|
│
|
||||||
|
└─ HTTP response with X-Fidelity, X-Warnings, X-Request-Id
|
||||||
|
```
|
||||||
|
|
||||||
|
## The document model in the middle
|
||||||
|
|
||||||
|
Every PDF-sourced conversion goes through one intermediate representation, the
|
||||||
|
**IDM** (`app/services/convert/idm/model.py`): a `Document` of `Page`s of
|
||||||
|
`Block`s of `TextSpan`s, with geometry in PDF points and the origin at the top
|
||||||
|
left of the page. Formatters read the IDM and never the PDF.
|
||||||
|
|
||||||
|
This is what makes eleven output formats affordable. Adding one means writing a
|
||||||
|
formatter against the IDM, not another PDF parser.
|
||||||
|
|
||||||
|
```
|
||||||
|
PDF ─► layout/pipeline.py ─► IDM ─┬─► formatters/docx_formatter.py ─► .docx
|
||||||
|
├─► formatters/text_formatters.py ─► .md/.html/.txt
|
||||||
|
├─► formatters/xlsx_formatter.py ─► .xlsx
|
||||||
|
├─► idm/serialize.py ─► .json
|
||||||
|
└─► writers/searchable_pdf.py ─► searchable .pdf
|
||||||
|
```
|
||||||
|
|
||||||
|
## How the IDM is built
|
||||||
|
|
||||||
|
`app/services/convert/layout/pipeline.py`, per page:
|
||||||
|
|
||||||
|
1. **Geometry** — glyph boxes and vector path operators. The native engine
|
||||||
|
supplies these when it is built; otherwise `layout/pypdf_geometry.py` walks
|
||||||
|
the content stream directly, resolving fonts, colours, text render modes and
|
||||||
|
link annotations. Advance widths come from `/Widths`, repaired by
|
||||||
|
`repair_width_map` when pypdf cannot build the map itself — subset TrueType
|
||||||
|
fonts without `/Encoding` otherwise under-report by about 35%, and because
|
||||||
|
producers draw a line as consecutive `Tj` operators the error accumulates
|
||||||
|
across it.
|
||||||
|
2. **Lines** — glyphs coalesced into lines and spans (`layout/glyphs.py`).
|
||||||
|
3. **Reading order** — recursive XY-cut (`layout/reading_order.py`). A vertical
|
||||||
|
cut is legal only through a band that no line's *extent* crosses, which is
|
||||||
|
what keeps two-column pages from interleaving.
|
||||||
|
4. **Paragraphs** — lines grouped into blocks (`layout/paragraphs.py`).
|
||||||
|
5. **Tables** — three detectors, most reliable first: ruled lattice
|
||||||
|
(`tables_lattice.py`), drawn rectangles (`tables_rects.py`), whitespace
|
||||||
|
columns (`tables_stream.py`), each gated by `table_plausibility.py`.
|
||||||
|
6. **Headers and footers** — repeated-band detection across pages
|
||||||
|
(`layout/headers_footers.py`).
|
||||||
|
7. **OCR**, when the page needs it (`ocr/rebuild.py`).
|
||||||
|
8. **Optimisation** — merge wrapped rows, reconcile cell fills, normalise
|
||||||
|
colours, collapse echoed text (`layout/idm_optimize.py`).
|
||||||
|
|
||||||
|
## Routing: the engine picks the path
|
||||||
|
|
||||||
|
`auto_policy.py` gathers cheap signals — document type, pages needing OCR,
|
||||||
|
image coverage, word count, and how *ruled* the pages are — and decides:
|
||||||
|
|
||||||
|
| Signal | Decision |
|
||||||
|
|---|---|
|
||||||
|
| clean digital text layer | no OCR |
|
||||||
|
| ≥95% of pages need OCR | force OCR |
|
||||||
|
| brochure-like pages, or image-led with little prose | positioned emit (DOCX) |
|
||||||
|
| ≥50 field-sized rectangles per page | positioned emit — it is a form |
|
||||||
|
| image-only, nothing to OCR | table detection off |
|
||||||
|
|
||||||
|
The form threshold is measured, not guessed: forms score 84 and 368 field
|
||||||
|
rectangles per page, the most heavily ruled prose in the corpus scores 33, and
|
||||||
|
everything else is under 3. `layout/form_signals.py` records the two text-shape
|
||||||
|
signals that were tried first and discarded because they discriminated
|
||||||
|
backwards.
|
||||||
|
|
||||||
|
Every decision lands on `document.meta.convert_policy`, so "why did page 7 come
|
||||||
|
out as a picture?" has an answer.
|
||||||
|
|
||||||
|
## Concurrency and shared state
|
||||||
|
|
||||||
|
Per-conversion state is in `ContextVar`s, so concurrent conversions cannot see
|
||||||
|
or clear each other's: the document cache, the cancel token and deadline, the
|
||||||
|
options, the policy decision, and the OCR detection plan. Each scope resets on
|
||||||
|
exit, so a pooled worker thread cannot leak one job's state into the next.
|
||||||
|
|
||||||
|
Three things are process-global and therefore locked:
|
||||||
|
|
||||||
|
| What | Where | Why locked |
|
||||||
|
|---|---|---|
|
||||||
|
| RapidOCR engines | `services/ocr.py` `_engine_lock` | RapidOCR sizes detection by mutating attributes on the shared engine; two conversions were overwriting each other's resolution |
|
||||||
|
| Font metric cache | `layout/pypdf_geometry.py` `_FONT_CACHE_LOCK` | eviction was a check-then-clear-then-write across conversions |
|
||||||
|
| PDFium rasterisation | `services/raster.py` `_render_lock` | PDFium is not re-entrant |
|
||||||
|
|
||||||
|
Recognition results are cached **across** conversions
|
||||||
|
(`services/ocr.py::_RecognitionCache`), keyed by a digest of the image plus the
|
||||||
|
Arabic flag. This is the one deliberately cross-conversion cache, and it exists
|
||||||
|
because recognition was being paid once per output format: one 42-page scan
|
||||||
|
converted to eleven targets ran OCR eleven times.
|
||||||
|
|
||||||
|
## Bounds
|
||||||
|
|
||||||
|
Nothing here is unbounded. Each limit degrades gracefully unless marked:
|
||||||
|
|
||||||
|
| Bound | Value | Behaviour at the limit |
|
||||||
|
|---|---|---|
|
||||||
|
| input size | 50 MB | reject (413) |
|
||||||
|
| page count | 200 | reject (413) |
|
||||||
|
| conversion deadline | 120 s (1800 s ceiling) | reject (504) |
|
||||||
|
| soft deadline | 80% of budget | stop early, return what is built |
|
||||||
|
| OCR page cap | 50 | warn, skip the rest |
|
||||||
|
| OCR wall budget | 1200 s | stop starting pages, keep the finished ones |
|
||||||
|
| raster cache | 64 MB | LRU eviction |
|
||||||
|
| geometry cache | 12 pages | LRU eviction |
|
||||||
|
| page-text cache | 64 pages | LRU eviction |
|
||||||
|
| OCR result cache | 256 entries / 64 MB / 30 min | LRU + TTL |
|
||||||
|
| in-flight conversions | CPU count, min 2 | 503 + Retry-After |
|
||||||
|
| queued conversions | 32 | 503 + Retry-After |
|
||||||
|
| job store | 256 jobs / 512 MB | evict oldest finished job |
|
||||||
|
| raster pixels | 80 M, 10 000 px edge | downscale |
|
||||||
|
| content stream | 12 MB, 20 000 path ops | stop walking, use what was read |
|
||||||
|
|
||||||
|
## What is deliberately not here
|
||||||
|
|
||||||
|
Authentication, durable job persistence, and object storage are the
|
||||||
|
surrounding platform's (docqube's). The job store is explicitly in-process and
|
||||||
|
non-durable; a restart loses queued and completed jobs. A second, weaker copy
|
||||||
|
of someone else's durability guarantee would be a liability, not a feature.
|
||||||
|
|
||||||
|
## Error taxonomy
|
||||||
|
|
||||||
|
`app/services/convert/errors.py`. Codes 1–7 describe a bad input; 8–11 describe
|
||||||
|
a conversion that did not complete. `retryable` on the response body tells a
|
||||||
|
client whether trying again could plausibly work.
|
||||||
|
|
||||||
|
| Code | HTTP | Retryable |
|
||||||
|
|---|---|---|
|
||||||
|
| `unsupported` | 415 | no |
|
||||||
|
| `encrypted` | 400 | no |
|
||||||
|
| `needs_ocr` | 422 | no |
|
||||||
|
| `malformed` | 400 | no |
|
||||||
|
| `resource_limit` | 413 | no |
|
||||||
|
| `missing_part` | 400 | no |
|
||||||
|
| `io` | 400 | no |
|
||||||
|
| `timeout` | 504 | **yes** |
|
||||||
|
| `cancelled` | 409 | no |
|
||||||
|
| `invalid_output` | 500 | no |
|
||||||
|
| `internal` | 500 | **yes** |
|
||||||
@@ -0,0 +1,126 @@
|
|||||||
|
# Configuration
|
||||||
|
|
||||||
|
Every knob is an environment variable. Nothing is hardcoded per deployment and
|
||||||
|
no secret has a default. Unset means "use the documented default"; a value that
|
||||||
|
cannot be parsed falls back to the default rather than failing the process.
|
||||||
|
|
||||||
|
The defaults are chosen so that a container with **no configuration at all**
|
||||||
|
runs correctly and safely. Reach for these only when you have a measurement
|
||||||
|
that says the default is wrong for your workload.
|
||||||
|
|
||||||
|
## Logging
|
||||||
|
|
||||||
|
| Variable | Default | Meaning |
|
||||||
|
|---|---|---|
|
||||||
|
| `CONVERT_LOG_LEVEL` | `INFO` | Standard level name. The stdlib root default is `WARNING`, which silently discarded this service's `INFO` events before logging was configured. |
|
||||||
|
| `CONVERT_LOG_FORMAT` | `text` | `text` for `key=value` lines a person can read; `json` for one object per line for a log shipper. |
|
||||||
|
|
||||||
|
Every line carries `cid=` — the correlation id. It comes from an inbound
|
||||||
|
`X-Request-Id` when present, otherwise it is minted per request, and it is
|
||||||
|
echoed back on the response. For an async job it is the job id, so the job's
|
||||||
|
work and the request that created it share a trace.
|
||||||
|
|
||||||
|
Fields whose **key** names a credential (`auth_token`, `api_key`, `password`,
|
||||||
|
`authorization`, `cookie`, …) are replaced with `***` by the formatter itself,
|
||||||
|
so a careless caller cannot leak one.
|
||||||
|
|
||||||
|
## Capacity and timeouts
|
||||||
|
|
||||||
|
| Variable | Default | Meaning |
|
||||||
|
|---|---|---|
|
||||||
|
| `CONVERT_MAX_CONCURRENT` | CPU count, min 2 | Conversions running at once. Beyond capacity a request gets 503 + `Retry-After`. |
|
||||||
|
| `CONVERT_MAX_QUEUED` | `32` | Admitted-and-waiting conversions. |
|
||||||
|
| `CONVERT_TIMEOUT_SECONDS` | `120` | Whole-conversion deadline. Capped at 1800 s so a misconfiguration cannot switch the deadline off. |
|
||||||
|
| `CONVERT_TIMEOUT_MAX_SECONDS` | `1800` | Ceiling on the OCR-extended budget. |
|
||||||
|
| `CONVERT_TIMEOUT_WORKERS` | `max(8, 4 × CPU)` | Size of the shared pool that runs timed operations. |
|
||||||
|
| `CONVERT_MAX_JOBS` | `256` | Jobs held in the in-process store. |
|
||||||
|
| `CONVERT_MAX_JOB_RESULT_BYTES` | `512 MB` | Total result bytes held. Whichever ceiling binds first evicts the oldest **finished** job; running jobs are never evicted. |
|
||||||
|
|
||||||
|
Sizing note: a conversion's peak is roughly its input plus its document model
|
||||||
|
plus a 64 MB raster cache. `CONVERT_MAX_CONCURRENT × ~200 MB` is a reasonable
|
||||||
|
first estimate of steady-state RSS.
|
||||||
|
|
||||||
|
## OCR
|
||||||
|
|
||||||
|
| Variable | Default | Meaning |
|
||||||
|
|---|---|---|
|
||||||
|
| `CONVERT_OCR_PAGE_TIMEOUT` | `30` | Seconds for one page's recognition. |
|
||||||
|
| `CONVERT_OCR_PAGE_CAP` | `50` | Pages OCR'd per document; beyond it the conversion warns and stops OCR'ing. |
|
||||||
|
| `CONVERT_OCR_WALL_BUDGET_SECONDS` | `1200` | Total OCR wall clock; the run ends by choice with a complete document rather than by a deadline that discards finished pages. |
|
||||||
|
| `CONVERT_OCR_ADAPTIVE_RESOLUTION` | on | Size detection to the page's own type size instead of a fixed 200 dpi. |
|
||||||
|
| `CONVERT_OCR_CACHE_ENTRIES` | `256` | Recognition results cached across conversions. `0` disables the cache. |
|
||||||
|
| `CONVERT_OCR_CACHE_BYTES` | `64 MB` | Byte ceiling for that cache. |
|
||||||
|
| `CONVERT_OCR_CACHE_TTL_SECONDS` | `1800` | How long a cached page stays valid. |
|
||||||
|
| `CONVERT_OCR_ARABIC` | `auto` | `auto` = on when the Arabic weights exist; `1`/`0` to force. The Arabic pass roughly doubles recognition time. |
|
||||||
|
| `CONVERT_OCR_ARABIC_WEIGHTS` | `models/ocr/ar/v5/rec.onnx` | Arabic recogniser weights. |
|
||||||
|
| `CONVERT_OCR_ARABIC_DICT` | `models/ocr/ar/v5/arabic_dict.txt` | Its character dictionary. |
|
||||||
|
| `CONVERT_OCR_INTRA_OP_THREADS` | usable CPUs | ONNX Runtime intra-op threads. ORT's own default reads `/proc/cpuinfo`, which does not know about a cgroup quota. |
|
||||||
|
| `CONVERT_OCR_SHARED_ALLOCATOR` | `1` | One arena across the six ONNX sessions instead of six. |
|
||||||
|
| `CONVERT_OCR_MEM_PATTERN` | `0` | ORT's memory pattern. Off because page shapes never repeat; it was worth 281 MB of an 880 MB peak and no measurable time. |
|
||||||
|
|
||||||
|
### Optional external OCR
|
||||||
|
|
||||||
|
| Variable | Default | Meaning |
|
||||||
|
|---|---|---|
|
||||||
|
| `MISTRAL_API_KEY` | unset | Enables the in-product Mistral/DocQube OCR path. Never logged. |
|
||||||
|
| `DOCQUBE_MISTRAL_OCR_URL` | Mistral's endpoint | Override the endpoint. |
|
||||||
|
| `MISTRAL_OCR_MODEL` | `mistral-ocr-latest` | Model name sent in the request. |
|
||||||
|
|
||||||
|
Unset, the engine uses only local RapidOCR and sends nothing anywhere. When
|
||||||
|
set, calls retry transient failures (429, 5xx, timeouts, reset connections)
|
||||||
|
three times with full-jitter exponential backoff, honour `Retry-After`, and
|
||||||
|
never retry a 4xx that will fail identically forever.
|
||||||
|
|
||||||
|
## Reconstruction
|
||||||
|
|
||||||
|
| Variable | Default | Meaning |
|
||||||
|
|---|---|---|
|
||||||
|
| `CONVERT_AUTO_RECONSTRUCT` | `1` | The engine routes the document itself. Off means callers must pass options explicitly. |
|
||||||
|
| `CONVERT_PDF_SCAN_STRATEGY` | heuristic | How pages are classified as needing OCR. |
|
||||||
|
| `CONVERT_PDF_SCAN_SAMPLE` | — | Pages sampled during routing. |
|
||||||
|
| `CONVERT_DOCX_PAGE_RASTER_FALLBACK` | on | Embed a page image when a page cannot be reconstructed, rather than inventing a layout for it. |
|
||||||
|
| `CONVERT_MD_PAGE_MARKERS` | off | Write page boundaries into Markdown output. |
|
||||||
|
| `CONVERT_MD_SIDECAR` | off | Use the optional `md-sidecar` extra. |
|
||||||
|
| `CONVERT_XLSX_PDF_MAX_ROWS` | — | Row ceiling for spreadsheet→PDF. |
|
||||||
|
| `CONVERT_XLSX_PDF_MAX_COLS_BAND` | — | Column-band ceiling for the same. |
|
||||||
|
|
||||||
|
## ML layout (optional)
|
||||||
|
|
||||||
|
All off unless weights are present. The engine is fully functional without
|
||||||
|
them; they sharpen region and table-structure detection.
|
||||||
|
|
||||||
|
| Variable | Default |
|
||||||
|
|---|---|
|
||||||
|
| `CONVERT_LAYOUT_ML` | off |
|
||||||
|
| `CONVERT_LAYOUT_ML_WEIGHTS` | — |
|
||||||
|
| `CONVERT_LAYOUT_ML_DEVICE` | cpu |
|
||||||
|
| `CONVERT_LAYOUT_ML_DPI` | — |
|
||||||
|
| `CONVERT_LAYOUT_ML_INPUT_SIZE` | — |
|
||||||
|
| `CONVERT_LAYOUT_ML_MIN_SCORE` | — |
|
||||||
|
| `CONVERT_LAYOUT_ML_PAGE_TIMEOUT` | `15` |
|
||||||
|
| `CONVERT_LAYOUT_ML_TABLE_STRUCTURE` | off |
|
||||||
|
| `CONVERT_LAYOUT_ML_TABLE_STRUCTURE_INPUT_SIZE` | — |
|
||||||
|
| `CONVERT_LAYOUT_ML_TABLE_STRUCTURE_MIN_SCORE` | — |
|
||||||
|
| `CONVERT_LAYOUT_ML_TABLE_STRUCTURE_TIMEOUT` | `10` |
|
||||||
|
|
||||||
|
## HTTP
|
||||||
|
|
||||||
|
| Variable | Default | Meaning |
|
||||||
|
|---|---|---|
|
||||||
|
| `CONVERT_CORS_ORIGINS` | `*` | Comma-separated allowed origins. |
|
||||||
|
| `CONVERT_CORS_CREDENTIALS` | `1` | Whether browsers may send cookies and `Authorization`. **Forced off while origins is `*`** — Starlette answers a wildcard credentialed request by echoing the caller's own origin, which would make every site on the internet an allowed credentialed caller. Name your origins to use credentials. |
|
||||||
|
|
||||||
|
## Debugging
|
||||||
|
|
||||||
|
| Variable | Default | Meaning |
|
||||||
|
|---|---|---|
|
||||||
|
| `CONVERT_DEBUG_IDM` | off | Dump the intermediate document model. |
|
||||||
|
| `CONVERT_DEBUG_DIR` | — | Where to write those dumps. |
|
||||||
|
|
||||||
|
Both write whole documents to disk. Leave them off in production.
|
||||||
|
|
||||||
|
## Settings object
|
||||||
|
|
||||||
|
`app/config.py` also exposes `PDFENGINE_*` settings via pydantic-settings
|
||||||
|
(`PDFENGINE_ENVIRONMENT`, the render-cache sizes). Those govern the
|
||||||
|
document-editing API, not conversion.
|
||||||
@@ -0,0 +1,115 @@
|
|||||||
|
# Supported formats, and what they honestly do
|
||||||
|
|
||||||
|
Two ideas are kept apart throughout this service, because conflating them is
|
||||||
|
how customers get surprised:
|
||||||
|
|
||||||
|
* **Reproduction** — the output is the input's pixels or bytes. Nothing is
|
||||||
|
interpreted, so nothing can be misinterpreted.
|
||||||
|
* **Reconstruction** — the output is the engine's reading of the document. It
|
||||||
|
is labelled lossy, because it is.
|
||||||
|
|
||||||
|
Every reconstruction target below is lossy. That is a property of the problem:
|
||||||
|
a PDF records where ink went, not what a paragraph was, and recovering the
|
||||||
|
second from the first is inference.
|
||||||
|
|
||||||
|
## Conversions
|
||||||
|
|
||||||
|
43 converters. `pdf → *` are reconstructions unless marked otherwise.
|
||||||
|
|
||||||
|
| From | To |
|
||||||
|
|---|---|
|
||||||
|
| `pdf` | `docx` `xlsx` `csv` `json` `md` `html` `txt` · `png` `jpeg` `tiff` (reproduction) · `pdf` (passthrough, or searchable) |
|
||||||
|
| `docx` | `pdf` `html` `md` `txt` `json` · `docx` (passthrough) |
|
||||||
|
| `xlsx` | `pdf` `csv` `html` `md` `txt` `json` |
|
||||||
|
| `pptx` | `pdf` `html` `md` `txt` `json` |
|
||||||
|
| `csv` | `xlsx` `pdf` `html` `md` |
|
||||||
|
| `md` | `pdf` `html` |
|
||||||
|
| `html` | `pdf` `docx` `md` |
|
||||||
|
| `txt` | `pdf` `docx` `md` |
|
||||||
|
| `png` `jpeg` `tiff` | `pdf` |
|
||||||
|
|
||||||
|
### `pdf → pdf`
|
||||||
|
|
||||||
|
Byte-identical passthrough by default, and that is a promise: a signed or
|
||||||
|
archived PDF that came back re-encoded would be a different artefact.
|
||||||
|
|
||||||
|
With an **explicit** `ocr_policy=force`, it instead returns a *searchable* PDF —
|
||||||
|
the original page images unchanged, with the recognised text laid over them at
|
||||||
|
render mode 3 (drawn, extractable, painting nothing). Automatic routing choosing
|
||||||
|
`force` is not enough to trigger this: that decision is made to help
|
||||||
|
reconstruction targets recover text, and treating it as permission to re-encode
|
||||||
|
the source would mean every scan came back as a different file.
|
||||||
|
|
||||||
|
The searchable path rasterises at 200 dpi, so a 300 dpi scan is resampled down.
|
||||||
|
That is why it is opt-in.
|
||||||
|
|
||||||
|
## Input limits
|
||||||
|
|
||||||
|
| Limit | Value | On exceeding |
|
||||||
|
|---|---|---|
|
||||||
|
| File size | 50 MB | 413 `resource_limit` |
|
||||||
|
| PDF pages | 200 | 413 `resource_limit` |
|
||||||
|
| Archive entries | bounded | 413 `resource_limit` |
|
||||||
|
| Archive uncompressed size | bounded | 413 `resource_limit` |
|
||||||
|
| Archive nesting depth | bounded | 413 `resource_limit` |
|
||||||
|
| Archive compression ratio | bounded | 413 `resource_limit` |
|
||||||
|
|
||||||
|
Legacy `.doc` and `.docm` are refused with a clear message rather than parsed
|
||||||
|
badly. A PDF with a **user** password is refused; one with only an **owner**
|
||||||
|
password is converted, with a warning saying so, because such files are readable
|
||||||
|
and common and refusing them turns away legitimate documents.
|
||||||
|
|
||||||
|
For inputs beyond these limits, split the document. Chunking is deliberately
|
||||||
|
the caller's decision: an engine that silently splits a 400-page contract and
|
||||||
|
reassembles it has made a structural choice nobody sanctioned.
|
||||||
|
|
||||||
|
## Known limitations
|
||||||
|
|
||||||
|
Each is disclosed in the output's warnings, not just here.
|
||||||
|
|
||||||
|
**Embedded Word charts** (`writers/pdf_from_docx.py`) render as a labelled
|
||||||
|
placeholder in `docx → pdf`. The chart is a full DrawingML plotting
|
||||||
|
specification; rendering it faithfully means implementing a chart engine, and
|
||||||
|
an approximation with wrong axes is worse than an honest placeholder.
|
||||||
|
|
||||||
|
**OCR page cap** — 50 pages per document by default. Beyond it the document
|
||||||
|
converts with a warning naming the pages that were skipped.
|
||||||
|
|
||||||
|
**Arabic OCR** roughly doubles recognition time and runs only when the weights
|
||||||
|
are present. Mixed-script documents are merged per line by score.
|
||||||
|
|
||||||
|
**Reading order on unusual layouts** — recursive XY-cut handles columns,
|
||||||
|
sidebars and pull-quotes. A layout with no straight cut anywhere (heavily
|
||||||
|
overlapping artwork, spiral text) degrades to top-to-bottom.
|
||||||
|
|
||||||
|
**Table detection is conservative by design.** Three detectors are tried, most
|
||||||
|
reliable first, each gated by a plausibility check. Prose that merely lines up
|
||||||
|
in columns will not become a table; a borderless table with irregular spacing
|
||||||
|
may not either. Soup tables are worse than missing ones.
|
||||||
|
|
||||||
|
**A page that cannot be reconstructed** is embedded as a page image rather than
|
||||||
|
having a layout invented for it, and says so in the warnings.
|
||||||
|
|
||||||
|
## Licensing
|
||||||
|
|
||||||
|
Every runtime dependency is permissively licensed and every model is freely
|
||||||
|
redistributable:
|
||||||
|
|
||||||
|
| Component | Licence |
|
||||||
|
|---|---|
|
||||||
|
| FastAPI, uvicorn, pydantic | MIT / BSD |
|
||||||
|
| pypdf | BSD-3-Clause |
|
||||||
|
| pypdfium2 (bindings) / PDFium | Apache-2.0 / BSD-3-Clause |
|
||||||
|
| RapidOCR ONNX Runtime | Apache-2.0 |
|
||||||
|
| ONNX Runtime | MIT |
|
||||||
|
| Pillow | MIT-CMU |
|
||||||
|
| python-docx, openpyxl | MIT |
|
||||||
|
| reportlab | BSD-3-Clause |
|
||||||
|
| beautifulsoup4, lxml | MIT / BSD |
|
||||||
|
| markdown-it-py | MIT |
|
||||||
|
| arabic-reshaper, mammoth | MIT / BSD |
|
||||||
|
|
||||||
|
No component is AGPL, no component is commercial, and no document is sent to a
|
||||||
|
third-party conversion service. The optional Mistral OCR path is off unless a
|
||||||
|
key is configured, and the engine says so in the conversion's warnings when it
|
||||||
|
is used.
|
||||||
@@ -0,0 +1,147 @@
|
|||||||
|
# Operational runbook
|
||||||
|
|
||||||
|
Written for whoever is on call. Every symptom below names the log event that
|
||||||
|
identifies it and the specific knob that changes it.
|
||||||
|
|
||||||
|
## Health
|
||||||
|
|
||||||
|
```sh
|
||||||
|
curl -s localhost:8000/health
|
||||||
|
```
|
||||||
|
|
||||||
|
Reports whether the native `pdfengine` module is present. It is **not** needed
|
||||||
|
for conversion — only for the document-editing API (`/documents`, compare,
|
||||||
|
protect, unlock, text replace). Those routes return 501 without it, by design.
|
||||||
|
|
||||||
|
## Reading the logs
|
||||||
|
|
||||||
|
Every line is `ts level logger cid=<id> event key=value …`.
|
||||||
|
|
||||||
|
```sh
|
||||||
|
# one request, end to end
|
||||||
|
docker logs svc 2>&1 | grep 'cid=8f2a1c0b4d99'
|
||||||
|
|
||||||
|
# what is failing, ranked
|
||||||
|
docker logs svc 2>&1 | grep -oP 'convert_failed .*error=\K\w+' | sort | uniq -c | sort -rn
|
||||||
|
|
||||||
|
# conversion throughput and latency
|
||||||
|
docker logs svc 2>&1 | grep convert_done | grep -oP 'elapsed_s=\K[\d.]+'
|
||||||
|
```
|
||||||
|
|
||||||
|
`cid` comes from the caller's `X-Request-Id` when supplied, so a trace that
|
||||||
|
starts upstream stays one trace. It is echoed on every response, which means a
|
||||||
|
customer's screenshot contains the key to their own logs.
|
||||||
|
|
||||||
|
### Events worth alerting on
|
||||||
|
|
||||||
|
| Event | Meaning | First action |
|
||||||
|
|---|---|---|
|
||||||
|
| `convert_rejected_at_capacity` | 503s are being returned | See "Rejecting requests" |
|
||||||
|
| `unhandled_exception` | an exception escaped a router | Read the traceback on the same line; this is a bug |
|
||||||
|
| `convert_invalid_output` | a converter produced an unopenable PDF | Bug in that writer; the caller correctly got a 500 |
|
||||||
|
| `timed_operation_abandoned` | an operation outlived its timeout | See "Rising memory" |
|
||||||
|
| `cancel_token_failed` | jobs cannot be cancelled | The job store is unreachable from the worker |
|
||||||
|
| `retry_exhausted` | an external OCR provider is down | See "External OCR" |
|
||||||
|
| `job_crashed` | an async job hit an unexpected error | Traceback is on the line |
|
||||||
|
| `ocr_engine_load_failed` | no recogniser | Scans will convert to page images only |
|
||||||
|
|
||||||
|
## Symptoms
|
||||||
|
|
||||||
|
### Rejecting requests (503 + `Retry-After`)
|
||||||
|
|
||||||
|
Working as intended: the process is at capacity and is refusing rather than
|
||||||
|
accepting work it cannot do. Check the numbers on the log line
|
||||||
|
(`running=`, `queued=`, `capacity=`).
|
||||||
|
|
||||||
|
- Sustained rejection at low CPU → raise `CONVERT_MAX_CONCURRENT`.
|
||||||
|
- Sustained rejection at high CPU → add replicas. The service is stateless per
|
||||||
|
conversion, so it scales horizontally without coordination.
|
||||||
|
- Bursty rejection → raise `CONVERT_MAX_QUEUED`; queued requests cost only the
|
||||||
|
buffered upload.
|
||||||
|
|
||||||
|
Do **not** raise these to make 503s stop without checking memory: each
|
||||||
|
concurrent conversion costs roughly its input plus ~200 MB.
|
||||||
|
|
||||||
|
### Rising memory
|
||||||
|
|
||||||
|
Check `timeout_pool_stats` in the `timed_operation_abandoned` lines. An
|
||||||
|
`abandoned_workers` count that climbs and does not fall means operations are
|
||||||
|
consistently outrunning their timeouts, and each one holds its working set
|
||||||
|
until it finishes.
|
||||||
|
|
||||||
|
1. `grep timed_operation_abandoned` and read `label=` — it names the operation.
|
||||||
|
2. If it is OCR, the page timeout is too tight for these documents; raise
|
||||||
|
`CONVERT_OCR_PAGE_TIMEOUT`, or lower `CONVERT_OCR_PAGE_CAP` to do less.
|
||||||
|
3. If `saturated=true` appears, the timeout pool is full and new timed work is
|
||||||
|
failing immediately. Raise `CONVERT_TIMEOUT_WORKERS` **only** after fixing
|
||||||
|
the cause; a larger pool holds more stuck work, it does not unstick it.
|
||||||
|
|
||||||
|
Steady-state memory that never comes down is normal up to a point: the OCR
|
||||||
|
result cache holds 64 MB and the job store up to 512 MB. Lower
|
||||||
|
`CONVERT_OCR_CACHE_BYTES` and `CONVERT_MAX_JOB_RESULT_BYTES` on a small box.
|
||||||
|
|
||||||
|
### Conversions timing out (504)
|
||||||
|
|
||||||
|
`convert_timeout` carries `elapsed_s` and `budget_s`.
|
||||||
|
|
||||||
|
- One document type only → likely a pathological page. `CONVERT_DEBUG_IDM=1`
|
||||||
|
with `CONVERT_DEBUG_DIR` set will dump the document model. Turn both off
|
||||||
|
afterwards.
|
||||||
|
- Scans → OCR is the cost. The engine already extends the budget for OCR
|
||||||
|
(`90 + pages × 22 × passes`); raise `CONVERT_TIMEOUT_MAX_SECONDS`, or set
|
||||||
|
`CONVERT_OCR_ARABIC=0` if the corpus has no Arabic, which halves recognition.
|
||||||
|
- Everything → the box is oversubscribed. Lower `CONVERT_MAX_CONCURRENT`.
|
||||||
|
|
||||||
|
A soft deadline fires at 80% of the budget and returns what has been built,
|
||||||
|
with warnings, rather than nothing. A 504 means even that did not finish.
|
||||||
|
|
||||||
|
### Scans converting with no text
|
||||||
|
|
||||||
|
Warnings on the response say what happened, per page:
|
||||||
|
|
||||||
|
- `no OCR text; embedded page image. Recognition failed — …` → OCR **crashed
|
||||||
|
or timed out**; the cause is in the message and in `ocr_page_engine_failed`.
|
||||||
|
- `no OCR text; embedded page image.` with no cause → the page genuinely has
|
||||||
|
no recognisable text.
|
||||||
|
- `skipped OCR — no page raster` → the renderer is unavailable; check
|
||||||
|
`ocr_engine_load_failed` and that pypdfium2 is installed.
|
||||||
|
- `OCR page cap reached` → raise `CONVERT_OCR_PAGE_CAP`.
|
||||||
|
|
||||||
|
### External OCR provider down
|
||||||
|
|
||||||
|
`retry_exhausted label=mistral-ocr`. The engine already backs off with jitter
|
||||||
|
and honours `Retry-After`, and falls back to local RapidOCR — conversions
|
||||||
|
succeed, more slowly. `retry_fatal` instead means a 4xx: check `MISTRAL_API_KEY`.
|
||||||
|
To stop trying entirely, unset `MISTRAL_API_KEY`.
|
||||||
|
|
||||||
|
### Slow conversions of the same document to many formats
|
||||||
|
|
||||||
|
Expected the first time, fast afterwards: recognition is cached across
|
||||||
|
conversions for 30 minutes. `ocr_cache_stats()` exposes hits and misses. If
|
||||||
|
hits stay at zero, the TTL is expiring first (raise
|
||||||
|
`CONVERT_OCR_CACHE_TTL_SECONDS`) or the cache is too small for the document
|
||||||
|
(raise `CONVERT_OCR_CACHE_ENTRIES`).
|
||||||
|
|
||||||
|
## Restarts
|
||||||
|
|
||||||
|
The job store is **in-process and non-durable**. A restart loses queued and
|
||||||
|
completed jobs; clients polling `/v1/jobs/{id}` will get 404 and must resubmit.
|
||||||
|
Durable job state belongs to the surrounding platform. Drain by stopping new
|
||||||
|
traffic and waiting for `convert_done`/`job_failed` to go quiet — conversions
|
||||||
|
are bounded by `CONVERT_TIMEOUT_SECONDS`, so the wait has a known ceiling.
|
||||||
|
|
||||||
|
## Scaling
|
||||||
|
|
||||||
|
A conversion is a self-contained unit of work with no cross-request state, so
|
||||||
|
replicas need no coordination. Two caveats:
|
||||||
|
|
||||||
|
1. The job store is per-process, so `/v1/jobs/{id}` must reach the replica that
|
||||||
|
created the job — session affinity, or use the synchronous endpoint.
|
||||||
|
2. The OCR result cache is per-process, so the cross-format saving only applies
|
||||||
|
when the same document's conversions land on the same replica.
|
||||||
|
|
||||||
|
## Deliberately out of scope
|
||||||
|
|
||||||
|
Authentication, durable job persistence, and object storage belong to the
|
||||||
|
surrounding platform (docqube). If you are looking for them here, they are not
|
||||||
|
missing — they are somewhere else on purpose.
|
||||||
@@ -92,6 +92,46 @@ markers = [
|
|||||||
"slow_ocr: end-to-end scan conversion; runs the recogniser (skips without it)",
|
"slow_ocr: end-to-end scan conversion; runs the recogniser (skips without it)",
|
||||||
]
|
]
|
||||||
|
|
||||||
|
# A warning nobody has to act on is a warning nobody reads, and a suite that
|
||||||
|
# prints eight of them every run is one where the ninth — the one that means a
|
||||||
|
# dependency has started deprecating something we depend on — arrives
|
||||||
|
# invisibly. So the deprecation family is an error, and the exceptions are
|
||||||
|
# listed here by name.
|
||||||
|
#
|
||||||
|
# The gate is deliberately scoped to Deprecation/PendingDeprecation/Future
|
||||||
|
# rather than to every warning category. Those three are the ones that mean
|
||||||
|
# "this will stop working on a future version", which is the class of thing a
|
||||||
|
# build should refuse to carry silently. ``ResourceWarning`` and
|
||||||
|
# ``UserWarning`` are left at their default behaviour: the first is noisy in
|
||||||
|
# ways that depend on the garbage collector rather than on our code, and the
|
||||||
|
# second is a legitimate runtime signal from openpyxl and friends that must not
|
||||||
|
# turn a valid conversion into a red test.
|
||||||
|
#
|
||||||
|
# Every ignore below is raised inside a third-party package, at a line we do not
|
||||||
|
# own and cannot change without forking it. Each is pinned to its exact message
|
||||||
|
# rather than to a category or a module, so a *different* deprecation from the
|
||||||
|
# same library still fails the run. When a pinned dependency is bumped, an entry
|
||||||
|
# that has become unnecessary shows up as an obsolete line here, not as silence.
|
||||||
|
#
|
||||||
|
# Warnings raised by our own code are deliberately absent from this list. The
|
||||||
|
# two deprecation notices the writers emit are asserted at their call sites with
|
||||||
|
# ``pytest.warns``, which is the difference between tolerating a warning and
|
||||||
|
# testing that it is still there.
|
||||||
|
filterwarnings = [
|
||||||
|
"error::DeprecationWarning",
|
||||||
|
"error::PendingDeprecationWarning",
|
||||||
|
"error::FutureWarning",
|
||||||
|
# starlette TestClient, module scope: the alias moved in anyio 4.2.
|
||||||
|
# Fixed upstream in starlette 0.46; we are pinned via fastapi 0.115.6.
|
||||||
|
"ignore:The anyio\\.abc\\.BlockingPortal alias is deprecated:DeprecationWarning",
|
||||||
|
# reportlab 4.2.5 rl_safe_eval, import time: a forward-looking notice about
|
||||||
|
# Python 3.14. We run 3.11/3.12; reportlab guards the attribute correctly.
|
||||||
|
"ignore:ast\\.NameConstant is deprecated:DeprecationWarning",
|
||||||
|
# beautifulsoup4 4.12.3 passes strip_cdata to lxml's HTMLParser, which lxml
|
||||||
|
# 5.3 now warns about. Removed in beautifulsoup4 4.13.
|
||||||
|
"ignore:The 'strip_cdata' option of HTMLParser\\(\\):DeprecationWarning",
|
||||||
|
]
|
||||||
|
|
||||||
# --- uv / PEP 735 dependency groups ------------------------------------------
|
# --- uv / PEP 735 dependency groups ------------------------------------------
|
||||||
[dependency-groups]
|
[dependency-groups]
|
||||||
dev = [
|
dev = [
|
||||||
|
|||||||
@@ -12,6 +12,70 @@ from collections.abc import Iterator
|
|||||||
import pytest
|
import pytest
|
||||||
from fastapi.testclient import TestClient
|
from fastapi.testclient import TestClient
|
||||||
|
|
||||||
|
# The test modules that exercise the document-editing API. Every one of them
|
||||||
|
# goes through ``POST /documents``, which needs the native ``pdfengine``
|
||||||
|
# pybind11 module; without it the router answers 501 by design and each of
|
||||||
|
# these files fails on its first assertion.
|
||||||
|
#
|
||||||
|
# Sixty-five failures that mean "this environment has no C++ build" are worse
|
||||||
|
# than useless: they are indistinguishable from a real regression, so a green
|
||||||
|
# suite becomes unattainable and nobody reads the red one. A capability the
|
||||||
|
# environment does not have is a *skip*. The engine's own conversion suite
|
||||||
|
# (``tests/convert``) is unaffected — it never needed the native module.
|
||||||
|
ENGINE_DEPENDENT_MODULES = frozenset(
|
||||||
|
{
|
||||||
|
"test_compare",
|
||||||
|
"test_final_extraction",
|
||||||
|
"test_font_regression",
|
||||||
|
"test_glyph_metrics",
|
||||||
|
"test_inplace_editing",
|
||||||
|
"test_layout",
|
||||||
|
"test_merge",
|
||||||
|
"test_protect",
|
||||||
|
"test_replace_text",
|
||||||
|
"test_unlock",
|
||||||
|
"test_watermark",
|
||||||
|
}
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def _engine_available() -> bool:
|
||||||
|
try:
|
||||||
|
from app.services import engine
|
||||||
|
except Exception:
|
||||||
|
return False
|
||||||
|
try:
|
||||||
|
return bool(engine.is_available())
|
||||||
|
except Exception:
|
||||||
|
return False
|
||||||
|
|
||||||
|
|
||||||
|
def pytest_configure(config: pytest.Config) -> None:
|
||||||
|
config.addinivalue_line(
|
||||||
|
"markers",
|
||||||
|
"needs_engine: requires the native pdfengine pybind11 module",
|
||||||
|
)
|
||||||
|
|
||||||
|
|
||||||
|
def pytest_collection_modifyitems(config: pytest.Config, items: list[pytest.Item]) -> None:
|
||||||
|
"""Skip — do not fail — what this environment cannot run.
|
||||||
|
|
||||||
|
Marking rather than deleting keeps the count visible: the summary line says
|
||||||
|
how many were skipped, so an environment that is *supposed* to have the
|
||||||
|
engine shows an obvious, countable anomaly instead of quietly passing less.
|
||||||
|
"""
|
||||||
|
if _engine_available():
|
||||||
|
return
|
||||||
|
skip = pytest.mark.skip(
|
||||||
|
reason=(
|
||||||
|
"native pdfengine module not built " "(app.services.engine.is_available() is False)"
|
||||||
|
)
|
||||||
|
)
|
||||||
|
for item in items:
|
||||||
|
module = item.nodeid.split("::")[0].rsplit("/", 1)[-1].removesuffix(".py")
|
||||||
|
if module in ENGINE_DEPENDENT_MODULES:
|
||||||
|
item.add_marker(skip)
|
||||||
|
|
||||||
|
|
||||||
@pytest.fixture()
|
@pytest.fixture()
|
||||||
def client() -> Iterator[TestClient]:
|
def client() -> Iterator[TestClient]:
|
||||||
|
|||||||
@@ -5,7 +5,6 @@ from __future__ import annotations
|
|||||||
import io
|
import io
|
||||||
import zipfile
|
import zipfile
|
||||||
|
|
||||||
import pytest
|
|
||||||
from openpyxl import load_workbook
|
from openpyxl import load_workbook
|
||||||
|
|
||||||
from app.services.convert.text.arabic_logical import (
|
from app.services.convert.text.arabic_logical import (
|
||||||
@@ -196,11 +195,3 @@ def test_html_formatter_wraps_lists_and_rtl():
|
|||||||
assert html.count("<li>") == 2
|
assert html.count("<li>") == 2
|
||||||
assert 'dir="rtl"' in html
|
assert 'dir="rtl"' in html
|
||||||
assert "<th>" in html and "<td>" in html
|
assert "<th>" in html and "<td>" in html
|
||||||
|
|
||||||
|
|
||||||
@pytest.mark.skipif(
|
|
||||||
True,
|
|
||||||
reason="optional Pillow Arabic font smoke — skip unless font bundled",
|
|
||||||
)
|
|
||||||
def test_pillow_arabic_word_optional():
|
|
||||||
pass
|
|
||||||
|
|||||||
@@ -8,7 +8,13 @@ from pathlib import Path
|
|||||||
import pytest
|
import pytest
|
||||||
|
|
||||||
_WEIGHTS = Path(__file__).resolve().parents[2] / "models" / "ocr" / "ar" / "v5" / "rec.onnx"
|
_WEIGHTS = Path(__file__).resolve().parents[2] / "models" / "ocr" / "ar" / "v5" / "rec.onnx"
|
||||||
_DOC_ROOT = Path(r"c:\Users\zaidabdulla\Downloads\DOC")
|
# Where the customer PDFs live. They are deliberately *not* in the repository,
|
||||||
|
# so the path has to come from outside it — and it must not be one developer's
|
||||||
|
# home directory hard-coded into a test, which is what it was: the gate could
|
||||||
|
# only ever open on one machine. ``CONVERT_OCR_ARABIC_DOC_ROOT`` names the
|
||||||
|
# folder; the historic location stays as the fallback so nobody's existing
|
||||||
|
# checkout changes behaviour.
|
||||||
|
_DOC_ROOT = Path(os.environ.get("CONVERT_OCR_ARABIC_DOC_ROOT") or Path.home() / "Downloads" / "DOC")
|
||||||
|
|
||||||
|
|
||||||
def _find_rfp() -> Path | None:
|
def _find_rfp() -> Path | None:
|
||||||
|
|||||||
@@ -3,10 +3,8 @@
|
|||||||
from __future__ import annotations
|
from __future__ import annotations
|
||||||
|
|
||||||
import io
|
import io
|
||||||
from pathlib import Path
|
|
||||||
|
|
||||||
import pypdf
|
import pypdf
|
||||||
import pytest
|
|
||||||
from pptx import Presentation
|
from pptx import Presentation
|
||||||
|
|
||||||
from app.services.convert.converters import all_plugins, pdf_to_pptx, pptx_to_pdf_convert
|
from app.services.convert.converters import all_plugins, pdf_to_pptx, pptx_to_pdf_convert
|
||||||
@@ -110,13 +108,78 @@ def test_pptx_to_pdf_round_trip():
|
|||||||
assert "+16%" in page_text
|
assert "+16%" in page_text
|
||||||
|
|
||||||
|
|
||||||
def test_pdf_to_pptx_live_w3c():
|
def _ruled_table_pdf() -> bytes:
|
||||||
w3c_path = Path("corpus/convert/_tmp_samples/real_web/w3c_pdf_table.pdf")
|
"""A one-page PDF holding a real, ruled table — built, not downloaded.
|
||||||
if not w3c_path.is_file():
|
|
||||||
pytest.skip("w3c_pdf_table.pdf not found on disk")
|
|
||||||
|
|
||||||
pdf_bytes = w3c_path.read_bytes()
|
This test used to read ``corpus/convert/_tmp_samples/real_web/w3c_pdf_table.pdf``
|
||||||
pptx_bytes, fidelity, warnings, media, score = pdf_to_pptx(pdf_bytes, "w3c_table.pdf")
|
and skip when it was absent. It was always absent: ``_tmp_samples`` is a
|
||||||
|
scratch download directory that is not in the repository and is not meant
|
||||||
|
to be, and the path was relative, so the test also depended on the working
|
||||||
|
directory pytest happened to be started from. The result was a permanent
|
||||||
|
skip — the pdf->pptx table path shipped with no test covering it at all.
|
||||||
|
|
||||||
|
Generating the fixture removes both problems. The table is drawn with real
|
||||||
|
vector text and real ruling lines, which is what the table detector keys
|
||||||
|
on, so the conversion exercised here is the same one a scanned-free
|
||||||
|
business PDF would take.
|
||||||
|
"""
|
||||||
|
from reportlab.lib import colors
|
||||||
|
from reportlab.lib.pagesizes import LETTER
|
||||||
|
from reportlab.lib.styles import getSampleStyleSheet
|
||||||
|
from reportlab.platypus import Paragraph, SimpleDocTemplate, Spacer, Table, TableStyle
|
||||||
|
|
||||||
|
buffer = io.BytesIO()
|
||||||
|
doc = SimpleDocTemplate(buffer, pagesize=LETTER)
|
||||||
|
styles = getSampleStyleSheet()
|
||||||
|
|
||||||
|
rows = [
|
||||||
|
["Cohort", "Participants", "Accuracy"],
|
||||||
|
["Disability", "128", "94%"],
|
||||||
|
["Control", "131", "96%"],
|
||||||
|
]
|
||||||
|
table = Table(rows, colWidths=[160, 110, 90])
|
||||||
|
table.setStyle(
|
||||||
|
TableStyle(
|
||||||
|
[
|
||||||
|
("GRID", (0, 0), (-1, -1), 0.75, colors.black),
|
||||||
|
("BACKGROUND", (0, 0), (-1, 0), colors.lightgrey),
|
||||||
|
("FONTNAME", (0, 0), (-1, 0), "Helvetica-Bold"),
|
||||||
|
("FONTSIZE", (0, 0), (-1, -1), 11),
|
||||||
|
("ALIGN", (1, 0), (-1, -1), "CENTER"),
|
||||||
|
]
|
||||||
|
)
|
||||||
|
)
|
||||||
|
|
||||||
|
doc.build(
|
||||||
|
[
|
||||||
|
Paragraph("Accessibility Conformance Summary", styles["Title"]),
|
||||||
|
Spacer(1, 18),
|
||||||
|
table,
|
||||||
|
]
|
||||||
|
)
|
||||||
|
return buffer.getvalue()
|
||||||
|
|
||||||
|
|
||||||
|
def _pptx_texts(pptx_bytes: bytes) -> list[str]:
|
||||||
|
"""Every string a slide carries, from tables and text frames alike."""
|
||||||
|
prs = Presentation(io.BytesIO(pptx_bytes))
|
||||||
|
texts: list[str] = []
|
||||||
|
for slide in prs.slides:
|
||||||
|
for shape in slide.shapes:
|
||||||
|
if shape.has_table:
|
||||||
|
for row in shape.table.rows:
|
||||||
|
texts.extend(cell.text for cell in row.cells)
|
||||||
|
elif shape.has_text_frame:
|
||||||
|
texts.append(shape.text)
|
||||||
|
return texts
|
||||||
|
|
||||||
|
|
||||||
|
def test_pdf_to_pptx_recovers_ruled_table():
|
||||||
|
"""A ruled table in a PDF must survive the trip to PPTX with its words."""
|
||||||
|
pdf_bytes = _ruled_table_pdf()
|
||||||
|
assert pdf_bytes.startswith(b"%PDF-")
|
||||||
|
|
||||||
|
pptx_bytes, fidelity, warnings, media, score = pdf_to_pptx(pdf_bytes, "conformance.pdf")
|
||||||
|
|
||||||
assert pptx_bytes[:2] == b"PK"
|
assert pptx_bytes[:2] == b"PK"
|
||||||
assert media == "application/vnd.openxmlformats-officedocument.presentationml.presentation"
|
assert media == "application/vnd.openxmlformats-officedocument.presentationml.presentation"
|
||||||
@@ -124,15 +187,10 @@ def test_pdf_to_pptx_live_w3c():
|
|||||||
prs = Presentation(io.BytesIO(pptx_bytes))
|
prs = Presentation(io.BytesIO(pptx_bytes))
|
||||||
assert len(prs.slides) >= 1
|
assert len(prs.slides) >= 1
|
||||||
|
|
||||||
# Verify slide text
|
joined = " ".join(_pptx_texts(pptx_bytes))
|
||||||
all_texts = []
|
# The header row, a data label and a figure: enough to prove the cells
|
||||||
for slide in prs.slides:
|
# travelled, not just that a shape was created.
|
||||||
for shape in slide.shapes:
|
assert "Disability" in joined
|
||||||
if shape.has_table:
|
assert "Participants" in joined
|
||||||
for row in shape.table.rows:
|
assert "Accuracy" in joined
|
||||||
all_texts.extend(cell.text for cell in row.cells)
|
assert "128" in joined
|
||||||
elif shape.has_text_frame:
|
|
||||||
all_texts.append(shape.text)
|
|
||||||
|
|
||||||
joined = " ".join(all_texts)
|
|
||||||
assert "Disability" in joined or "Participants" in joined or "Accuracy" in joined
|
|
||||||
|
|||||||
@@ -5,6 +5,7 @@ from __future__ import annotations
|
|||||||
import io
|
import io
|
||||||
import zipfile
|
import zipfile
|
||||||
|
|
||||||
|
import pytest
|
||||||
from docx import Document
|
from docx import Document
|
||||||
from openpyxl import load_workbook
|
from openpyxl import load_workbook
|
||||||
|
|
||||||
@@ -41,7 +42,13 @@ def test_docx_writer_paragraphs_and_table():
|
|||||||
)
|
)
|
||||||
],
|
],
|
||||||
)
|
)
|
||||||
data = build_docx_from_pdf_text(doc_text)
|
# ``build_docx_from_pdf_text`` is deprecated in favour of
|
||||||
|
# ``formatters.docx_formatter``. The legacy entry point still has callers,
|
||||||
|
# so it is still tested — but the deprecation notice is part of the
|
||||||
|
# contract, not noise: asserting it here means silently dropping the
|
||||||
|
# warning (or the function) fails the suite instead of passing quietly.
|
||||||
|
with pytest.warns(DeprecationWarning, match="docx_writer.build_docx_from_pdf_text"):
|
||||||
|
data = build_docx_from_pdf_text(doc_text)
|
||||||
with zipfile.ZipFile(io.BytesIO(data)) as zf:
|
with zipfile.ZipFile(io.BytesIO(data)) as zf:
|
||||||
assert "[Content_Types].xml" in zf.namelist()
|
assert "[Content_Types].xml" in zf.namelist()
|
||||||
doc = Document(io.BytesIO(data))
|
doc = Document(io.BytesIO(data))
|
||||||
@@ -64,7 +71,8 @@ def test_xlsx_writer_cells():
|
|||||||
)
|
)
|
||||||
],
|
],
|
||||||
)
|
)
|
||||||
data, warnings = build_xlsx_from_pdf_text(doc_text)
|
with pytest.warns(DeprecationWarning, match="xlsx_writer.build_xlsx_from_pdf_text"):
|
||||||
|
data, warnings = build_xlsx_from_pdf_text(doc_text)
|
||||||
assert not any("No table" in w for w in warnings)
|
assert not any("No table" in w for w in warnings)
|
||||||
wb = load_workbook(io.BytesIO(data))
|
wb = load_workbook(io.BytesIO(data))
|
||||||
ws = wb.active
|
ws = wb.active
|
||||||
|
|||||||
Reference in New Issue
Block a user