Make doc_modeler resilient to SQLite "database is locked"

A refresh on a large library aborted the whole doc_modeler run on the
first lock error, so the ~20k stranded docs never got modeled.

doc_modeler held one write transaction across a whole batch of 10 docs
while doing slow per-doc extraction (a PDF/epub can be tens of MB). When
another connection committed mid-batch, the deferred transaction failed
to upgrade to a write with SQLITE_BUSY_SNAPSHOT ("database is locked",
which busy_timeout does not absorb -- the same trap that motivated the
short-transaction rewrite of apply_indexers). The per-item error handler
then did `logger.error(f'... {file_group}')`, which lazy-loaded an
attribute on the now-rolled-back session and raised a *second* exception,
escaping the handler and aborting the entire modeler.

Restructure:
- Pick each batch of candidate ids in a short read-only transaction, then
  model each doc in its own short write transaction. A lock/error on one
  doc rolls back only that doc and cannot poison the rest of the run.
- Retry a doc a few times on "database is locked" -- a fresh transaction
  gets a fresh snapshot and succeeds.
- Log the plain file_group id on failure; never touch the ORM object on a
  possibly rolled-back session.
- Track only *failed* ids for the termination guard (successes are
  excluded by the Doc.id IS NULL gate), keeping the notin_ set small and
  well under SQLite's bound-variable limit.

Adds test_doc_modeler_survives_database_locked.

Co-Authored-By: Claude Opus 4.8 (1M context) <noreply@anthropic.com>

modules/docs/__init__.py

@@ -1,8 +1,9 @@
 import asyncio
 import logging
-from typing import Callable, List, Tuple
+from typing import Callable, List
 
 from sqlalchemy import or_
+from sqlalchemy.exc import OperationalError
 from sqlalchemy.orm import Session
 
 from wrolpi.common import register_modeler, register_refresh_cleanup, \
@@ -19,19 +20,34 @@ from .models import Doc, DocSection, DOC_MIMETYPES, COMIC_BOOK_SUFFIXES, EPUB_MI
 logger = logging.getLogger(__name__)
 
 DOC_PROCESSING_LIMIT = 10
+# Retries for a single doc when it hits SQLite's "database is locked" (SQLITE_BUSY_SNAPSHOT).
+DOC_LOCK_RETRIES = 3
 
 
 @register_modeler
 async def doc_modeler(progress_callback: Callable[[int], None] = None):
-    """Searches for doc files (epub, mobi, pdf, docx, doc, odt, cbz, cbr) and models them."""
+    """Searches for doc files (epub, mobi, pdf, docx, doc, odt, cbz, cbr) and models them.
+
+    Each doc is modeled in its own short transaction.  Modeling reads a large file (a PDF/epub can
+    be tens of MB) and can take seconds; holding one write transaction across a whole batch let
+    another connection commit in the meantime, so the deferred transaction failed to upgrade to a
+    write with SQLite's `SQLITE_BUSY_SNAPSHOT` ("database is locked", which `busy_timeout` does not
+    absorb) -- and the error handler then crashed on the rolled-back session, aborting the entire
+    modeler run.  Per-doc transactions keep the write window short and isolate failures so one
+    locked/broken doc cannot poison the rest of the run.
+    """
     total_processed = 0
-    # Track FileGroups already attempted in this run so a doc that fails to model (and therefore
-    # keeps matching the `Doc.id IS NULL` gate below) cannot be re-selected forever, which would
-    # hang this loop and starve later docs.  Failed docs are simply retried on the next refresh.
-    attempted_ids: set = set()
+    # Ids of docs that failed to model this run.  A failed doc keeps matching the `Doc.id IS NULL`
+    # gate below, so without excluding it the loop would re-select it forever, hang, and starve
+    # later docs.  Successfully-modeled docs are excluded automatically (they gain a Doc row), so
+    # only failures need tracking -- keeping this set (and the `notin_` clause) small.  Failed docs
+    # are retried on the next refresh.
+    failed_ids: set = set()
     while True:
-        with get_db_session(commit=True) as session:
-            query = session.query(FileGroup, Doc) \
+        # Short read-only transaction to choose the next batch of ids.  Do NOT hold it open across
+        # the slow per-doc modeling below.
+        with get_db_session() as session:
+            query = session.query(FileGroup.id) \
                 .outerjoin(Doc, Doc.file_group_id == FileGroup.id) \
                 .filter(
                 or_(
@@ -47,38 +63,51 @@ async def doc_modeler(progress_callback: Callable[[int], None] = None):
                     FileGroup.indexed == False,
                 ),
             )
-            if attempted_ids:
-                query = query.filter(FileGroup.id.notin_(attempted_ids))
-            file_groups: List[Tuple[FileGroup, Doc]] = list(query.limit(DOC_PROCESSING_LIMIT))
+            if failed_ids:
+                query = query.filter(FileGroup.id.notin_(failed_ids))
+            fg_ids: List[int] = [row[0] for row in query.limit(DOC_PROCESSING_LIMIT).all()]
 
-            processed = 0
-            for file_group, doc in file_groups:
-                processed += 1
-                attempted_ids.add(file_group.id)
+        if not fg_ids:
+            break
+
+        for fg_id in fg_ids:
+            for attempt in range(DOC_LOCK_RETRIES):
                 try:
-                    if PYTEST:
-                        session.expire(file_group)
-
-                    doc = _model_doc(file_group, session)
-                    session.add(doc)
-                    file_group.model = Doc.__tablename__
-                    file_group.indexed = True
+                    # One short write transaction per doc.
+                    with get_db_session(commit=True) as session:
+                        file_group = session.query(FileGroup).get(fg_id)
+                        if file_group is None:
+                            # Deleted between discovery and now; nothing to model.
+                            break
+                        doc = _model_doc(file_group, session)
+                        session.add(doc)
+                        file_group.model = Doc.__tablename__
+                        file_group.indexed = True
+                    break
+                except OperationalError as e:
+                    # Another connection committed during our transaction.  Retrying with a fresh
+                    # transaction gets a fresh snapshot and usually succeeds.
+                    if 'locked' in str(e).lower() and attempt < DOC_LOCK_RETRIES - 1:
+                        await asyncio.sleep(0.2 * (attempt + 1))
+                        continue
+                    logger.error(f'Failed to model doc file_group_id={fg_id}: database error', exc_info=e)
+                    failed_ids.add(fg_id)
+                    break
                 except Exception as e:
-                    logger.error(f'Failed to index doc {file_group}', exc_info=e)
-                    file_group.indexed = True  # Don't retry on failure.
+                    # Never reference the ORM object here: after a failed flush the session is
+                    # rolled back, so touching a lazy/expired attribute (e.g. in its repr) raises a
+                    # second exception that would abort the whole modeler.  Log the plain id only.
+                    logger.error(f'Failed to model doc file_group_id={fg_id}', exc_info=e)
+                    failed_ids.add(fg_id)
                     if PYTEST:
                         raise
+                    break
+            # Yield so a cancel/other tasks can run between docs.
+            await asyncio.sleep(0)
 
-            session.commit()
-
-            total_processed += len(file_groups)
-            if progress_callback and len(file_groups) > 0:
-                progress_callback(total_processed)
-
-            if processed < DOC_PROCESSING_LIMIT:
-                break
-
-        await asyncio.sleep(0)
+        total_processed += len(fg_ids)
+        if progress_callback:
+            progress_callback(total_processed)
 
 
 def _model_doc(file_group: FileGroup, session: Session) -> Doc:

modules/docs/test/test_doc_modeler.py

@@ -1,10 +1,12 @@
 """Tests for the doc_modeler."""
 import asyncio
 import shutil
+import sqlite3
 from unittest.mock import patch
 
 import pytest
 from PIL import Image
+from sqlalchemy.exc import OperationalError
 
 from modules.docs import doc_modeler
 from modules.docs.models import Doc, DocSection
@@ -173,6 +175,41 @@ async def test_doc_modeler_terminates_on_persistent_failure(async_client, test_s
     assert test_session.query(Doc).count() == 0
 
 
+@pytest.mark.asyncio
+async def test_doc_modeler_survives_database_locked(async_client, test_session, test_directory, refresh_files):
+    """A transient SQLite "database is locked" on one doc must not abort the whole modeler run.
+
+    Regression: doc_modeler held one write transaction across a whole batch of slow extractions.
+    When another connection committed mid-batch, the deferred transaction failed to upgrade with
+    SQLITE_BUSY_SNAPSHOT ("database is locked"), the error handler crashed on the rolled-back
+    session, and the entire run aborted -- so no further docs were modeled.  Each doc now runs in
+    its own short transaction and a lock is retried.
+    """
+    ebook_dir = test_directory / 'ebooks'
+    ebook_dir.mkdir(parents=True)
+    for i in range(3):
+        shutil.copy(PROJECT_DIR / 'test/ebook example.epub', ebook_dir / f'book_{i:03d}.epub')
+
+    from modules.docs import _model_doc as real_model_doc
+
+    calls = {'n': 0}
+
+    def flaky_model_doc(file_group, session):
+        # Fail the very first modeling attempt with a lock error, then behave normally.  Proves the
+        # run recovers (retries the doc, keeps modeling the rest) instead of aborting.
+        calls['n'] += 1
+        if calls['n'] == 1:
+            raise OperationalError('stmt', {}, sqlite3.OperationalError('database is locked'))
+        return real_model_doc(file_group, session)
+
+    with patch('modules.docs._model_doc', side_effect=flaky_model_doc):
+        await refresh_files()
+
+    # All three ebooks were modeled despite the initial lock error.
+    assert test_session.query(Doc).count() == 3
+    assert calls['n'] >= 4  # 1 failed attempt + 1 retry + 2 more docs.
+
+
 @pytest.mark.asyncio
 async def test_doc_modeler_processes_more_than_batch_limit(async_client, test_session, test_directory):
     """Doc modeler processes more than one batch of files (limit=10)."""