Files
FabledCurator/tests/test_maintenance.py
T
bvandeusen a85880f965 fix(import): split archive imports into their own task + budget; archive-aware recovery sweeps
Operator-flagged 2026-05-28: import_media_file on target 1645019 hit
SoftTimeLimitExceeded at exactly 5.0 min. Their diagnosis was correct —
the timeout covered the WHOLE archive, not per object. Importer._import_archive
(importer.py:409) runs the full per-member pipeline (sha256 + pHash +
dedup query + copy + provenance) for EVERY media member inline, all
under import_media_file's single 300s soft limit. A single media file
is sub-second; a multi-hundred-member archive blows the budget. They
shared one task name and one timeout.

**Split archive into its own task**

- New `import_archive_file` task: same body as import_media_file
  (dispatch is by file-kind inside Importer.import_one) but
  soft=30min / hard=35min. Shared `_run_import_task` helper holds the
  flip-to-processing + resilience-contract wrapper; both tasks call it.
- New `enqueue_import(task_id, task_type)` router — single source of
  truth for media-vs-archive dispatch. Used by all three enqueue sites:
  scan_directory, /api/import/retry-failed, recover_interrupted_tasks.
- scan_directory now sets ImportTask.task_type = "archive" when
  is_archive(entry) (the model field already existed, anticipating
  this; scan was hardcoding "media").
- import_archive_file routes to the existing 'import' queue via the
  task_routes `import_file.*` wildcard — no worker config change.

**Archive-aware recovery sweeps**

Both sweeps would otherwise preempt a legitimately-running archive:

- recover_interrupted_tasks (ImportTask 'processing' sweep): now
  task-type-aware. Media stays at STUCK_THRESHOLD_MINUTES (5); archives
  get ARCHIVE_STUCK_THRESHOLD_MINUTES (40 = 5-min buffer past the
  35-min hard limit). Single UPDATE with an OR predicate over the two
  (task_type, cutoff) pairs; requeue routes via enqueue_import.
- recover_stalled_task_runs (TaskRun 'running' sweep): now supports
  per-task-name overrides (TASK_STUCK_THRESHOLD_MINUTES) layered above
  the per-queue overrides added for ml. import_archive_file gets 40 min
  while the 'import' queue stays at the 5-min default for single-file
  imports. Precedence: task_name → queue → default, each pass excluding
  rows claimed by a higher-precedence pass so every row is touched once.

**Tests**

- test_import_archive_file_registered
- test_recover_stalled_task_runs_archive_task_uses_longer_threshold —
  pins that a 10-min archive task-run survives, a 50-min one is flagged,
  and a same-queue 10-min media import is flagged at the default.
- _make_task_run gains queue= + task_name= params.

After deploy: archive imports get a 30-min budget and aren't preempted
by either sweep; single-file imports keep their tight 5-min detection.
2026-05-27 22:45:11 -04:00

452 lines
15 KiB
Python

"""Unit tests for the maintenance tasks. Eager-mode Celery so the task
function runs synchronously inside the same DB transaction as the test.
"""
from datetime import UTC, datetime, timedelta
import pytest
from backend.app.celery_app import celery
from backend.app.models import ImportBatch, ImportTask
pytestmark = pytest.mark.integration
@pytest.fixture(autouse=True)
def eager():
celery.conf.task_always_eager = True
yield
celery.conf.task_always_eager = False
def _make_batch(session) -> int:
batch = ImportBatch(triggered_by="manual", source_path="/import", scan_mode="quick")
session.add(batch)
session.flush()
return batch.id
def test_recover_interrupted_only_old(db_sync, monkeypatch):
batch_id = _make_batch(db_sync)
now = datetime.now(UTC)
# "Fresh" must sit comfortably under whatever STUCK_THRESHOLD_MINUTES
# currently is (5 min as of 2026-05-24, tightened from 30); 30
# seconds is well below any reasonable threshold. "Stale" stays at
# 2 hours so the test remains valid if the threshold ever moves
# back up.
fresh = ImportTask(
batch_id=batch_id, source_path="/import/a.jpg", task_type="media",
status="processing", started_at=now - timedelta(seconds=30),
)
stale = ImportTask(
batch_id=batch_id, source_path="/import/b.jpg", task_type="media",
status="processing", started_at=now - timedelta(hours=2),
)
db_sync.add_all([fresh, stale])
db_sync.commit()
# Isolate the recover task: under eager Celery, the real
# import_media_file.delay() would run inline against the nonexistent
# /import/b.jpg and flip the just-requeued row 'queued' -> 'skipped'.
from backend.app.tasks import import_file
dispatched: list[int] = []
monkeypatch.setattr(
import_file.import_media_file, "delay", dispatched.append
)
from backend.app.tasks.maintenance import recover_interrupted_tasks
recovered = recover_interrupted_tasks.apply().get()
assert recovered == 1
db_sync.refresh(fresh)
db_sync.refresh(stale)
assert fresh.status == "processing"
assert stale.status == "queued"
assert stale.started_at is None
assert dispatched == [stale.id]
def test_recover_interrupted_sweeps_pending_orphans_to_failed(db_sync, monkeypatch):
"""A scan that creates ImportTask rows but crashes before the second
pass (transition to 'queued' + .delay()) leaves rows orphaned at
status='pending'. The sweep flips them to 'failed' so the operator
can drain via /api/import/retry-failed without thundering-herding.
Banked 2026-05-25 after operator hit 5490 stuck pending rows.
"""
from backend.app.tasks import import_file
monkeypatch.setattr(import_file.import_media_file, "delay", lambda *_: None)
batch_id = _make_batch(db_sync)
now = datetime.now(UTC)
fresh_pending = ImportTask(
batch_id=batch_id, source_path="/import/fresh.jpg", task_type="media",
status="pending",
)
db_sync.add(fresh_pending)
db_sync.flush()
# created_at defaults to now() server-side; fresh row stays untouched.
# Two stale rows simulating the orphan pile: one 'pending', one
# 'queued' (scanner crashed AFTER transitioning some rows but
# before all). Both should sweep.
stale_pending = ImportTask(
batch_id=batch_id, source_path="/import/stale1.jpg", task_type="media",
status="pending",
)
stale_queued = ImportTask(
batch_id=batch_id, source_path="/import/stale2.jpg", task_type="media",
status="queued",
)
db_sync.add_all([stale_pending, stale_queued])
db_sync.flush()
# Backdate created_at past the orphan cutoff (30 min).
from sqlalchemy import update as _upd
db_sync.execute(
_upd(ImportTask)
.where(ImportTask.id.in_([stale_pending.id, stale_queued.id]))
.values(created_at=now - timedelta(hours=2))
)
db_sync.commit()
from backend.app.tasks.maintenance import recover_interrupted_tasks
touched = recover_interrupted_tasks.apply().get()
assert touched == 2
db_sync.refresh(fresh_pending)
db_sync.refresh(stale_pending)
db_sync.refresh(stale_queued)
assert fresh_pending.status == "pending" # fresh row untouched
assert stale_pending.status == "failed"
assert stale_queued.status == "failed"
assert "orphan" in (stale_pending.error or "")
def test_recover_interrupted_handles_both_stuck_and_orphans(db_sync, monkeypatch):
"""One sweep tick handles both 'processing' crashes AND
'pending'/'queued' orphans in a single pass."""
from backend.app.tasks import import_file
dispatched: list[int] = []
monkeypatch.setattr(
import_file.import_media_file, "delay", dispatched.append
)
batch_id = _make_batch(db_sync)
now = datetime.now(UTC)
stuck = ImportTask(
batch_id=batch_id, source_path="/import/stuck.jpg", task_type="media",
status="processing", started_at=now - timedelta(hours=2),
)
orphan = ImportTask(
batch_id=batch_id, source_path="/import/orphan.jpg", task_type="media",
status="pending",
)
db_sync.add_all([stuck, orphan])
db_sync.flush()
from sqlalchemy import update as _upd
db_sync.execute(
_upd(ImportTask).where(ImportTask.id == orphan.id)
.values(created_at=now - timedelta(hours=2))
)
db_sync.commit()
from backend.app.tasks.maintenance import recover_interrupted_tasks
touched = recover_interrupted_tasks.apply().get()
assert touched == 2
db_sync.refresh(stuck)
db_sync.refresh(orphan)
assert stuck.status == "queued"
assert orphan.status == "failed"
assert dispatched == [stuck.id] # stuck rows re-enqueue; orphans don't
def test_cleanup_old_deletes_finished_old(db_sync):
batch_id = _make_batch(db_sync)
now = datetime.now(UTC)
old_complete = ImportTask(
batch_id=batch_id, source_path="/import/a.jpg", task_type="media",
status="complete", finished_at=now - timedelta(days=10),
)
recent_complete = ImportTask(
batch_id=batch_id, source_path="/import/b.jpg", task_type="media",
status="complete", finished_at=now - timedelta(days=2),
)
old_pending = ImportTask(
batch_id=batch_id, source_path="/import/c.jpg", task_type="media",
status="pending",
)
db_sync.add_all([old_complete, recent_complete, old_pending])
db_sync.commit()
from backend.app.tasks.maintenance import cleanup_old_tasks
deleted = cleanup_old_tasks.apply().get()
assert deleted == 1
remaining = {t.source_path for t in db_sync.query(ImportTask).all()}
assert remaining == {"/import/b.jpg", "/import/c.jpg"}
# --- FC-3i: task_run sweep + retention -----------------------------
def _make_task_run(db_sync, *, status, started_at, finished_at=None,
error_type=None, queue="default",
task_name="backend.app.tasks.fake.t"):
from backend.app.models import TaskRun
row = TaskRun(
celery_task_id="x",
queue=queue,
task_name=task_name,
target_id=1,
started_at=started_at,
finished_at=finished_at,
duration_ms=1000 if finished_at else None,
status=status,
error_type=error_type,
error_message="x" if status in ("error", "timeout") else None,
)
db_sync.add(row)
db_sync.flush()
return row.id
def test_recover_stalled_task_runs_flips_old_running_to_error(db_sync):
from sqlalchemy import select
from backend.app.models import TaskRun
from backend.app.tasks.maintenance import recover_stalled_task_runs
now = datetime.now(UTC)
stale_id = _make_task_run(
db_sync, status="running", started_at=now - timedelta(minutes=10),
)
db_sync.commit()
recovered = recover_stalled_task_runs.apply().get()
assert recovered == 1
db_sync.expire_all()
status = db_sync.execute(
select(TaskRun.status).where(TaskRun.id == stale_id)
).scalar_one()
error_type = db_sync.execute(
select(TaskRun.error_type).where(TaskRun.id == stale_id)
).scalar_one()
assert status == "error"
assert error_type == "RecoverySweep"
def test_recover_stalled_task_runs_skips_fresh_running(db_sync):
from sqlalchemy import select
from backend.app.models import TaskRun
from backend.app.tasks.maintenance import recover_stalled_task_runs
now = datetime.now(UTC)
fresh_id = _make_task_run(
db_sync, status="running", started_at=now - timedelta(seconds=30),
)
db_sync.commit()
recovered = recover_stalled_task_runs.apply().get()
assert recovered == 0
def test_recover_stalled_task_runs_ml_queue_uses_longer_threshold(db_sync):
"""ml-queue tasks (tag_and_embed video branch) legitimately run
past the default 5-min threshold. The sweep must NOT flag an
ml-queue task that's only been running 10 min — the override
threshold (25 min via QUEUE_STUCK_THRESHOLD_MINUTES) protects
in-flight video tagging. Operator-flagged 2026-05-28 after
image 6288 (mp4) was marked failed at the 5-min tick mid-run."""
from sqlalchemy import select
from backend.app.models import TaskRun
from backend.app.tasks.maintenance import recover_stalled_task_runs
now = datetime.now(UTC)
# 10-min-old ml-queue row: stale by the default 5-min rule but
# fresh by the 25-min ml override. Must survive the sweep.
ml_fresh_id = _make_task_run(
db_sync, status="running", queue="ml",
started_at=now - timedelta(minutes=10),
)
# 30-min-old ml-queue row: past even the ml override. Must be
# flagged.
ml_stale_id = _make_task_run(
db_sync, status="running", queue="ml",
started_at=now - timedelta(minutes=30),
)
db_sync.commit()
recovered = recover_stalled_task_runs.apply().get()
assert recovered == 1
db_sync.expire_all()
ml_fresh_status = db_sync.execute(
select(TaskRun.status).where(TaskRun.id == ml_fresh_id)
).scalar_one()
ml_stale_status = db_sync.execute(
select(TaskRun.status).where(TaskRun.id == ml_stale_id)
).scalar_one()
assert ml_fresh_status == "running"
assert ml_stale_status == "error"
def test_recover_stalled_task_runs_archive_task_uses_longer_threshold(db_sync):
"""import_archive_file shares the 'import' queue with fast
single-file import_media_file, so it gets a per-task-name override
(40 min) while the import queue stays at the 5-min default. A
10-min-old archive task-run must survive; a 50-min-old one is
flagged. Operator-flagged 2026-05-28."""
from sqlalchemy import select
from backend.app.models import TaskRun
from backend.app.tasks.maintenance import recover_stalled_task_runs
archive_name = "backend.app.tasks.import_file.import_archive_file"
now = datetime.now(UTC)
# Fast single-file import on the same queue, 10 min old → flagged
# by the default 5-min rule.
media_id = _make_task_run(
db_sync, status="running", queue="import",
task_name="backend.app.tasks.import_file.import_media_file",
started_at=now - timedelta(minutes=10),
)
# Archive on the same queue, 10 min old → survives (40-min override).
archive_fresh_id = _make_task_run(
db_sync, status="running", queue="import",
task_name=archive_name,
started_at=now - timedelta(minutes=10),
)
# Archive 50 min old → past even the 40-min override → flagged.
archive_stale_id = _make_task_run(
db_sync, status="running", queue="import",
task_name=archive_name,
started_at=now - timedelta(minutes=50),
)
db_sync.commit()
recovered = recover_stalled_task_runs.apply().get()
assert recovered == 2 # media + stale archive
db_sync.expire_all()
def _status(_id):
return db_sync.execute(
select(TaskRun.status).where(TaskRun.id == _id)
).scalar_one()
assert _status(media_id) == "error"
assert _status(archive_fresh_id) == "running"
assert _status(archive_stale_id) == "error"
db_sync.expire_all()
status = db_sync.execute(
select(TaskRun.status).where(TaskRun.id == fresh_id)
).scalar_one()
assert status == "running"
def test_prune_task_runs_deletes_ok_older_than_24h(db_sync):
from sqlalchemy import select
from backend.app.models import TaskRun
from backend.app.tasks.maintenance import prune_task_runs
now = datetime.now(UTC)
old_id = _make_task_run(
db_sync, status="ok",
started_at=now - timedelta(hours=30),
finished_at=now - timedelta(hours=29),
)
recent_id = _make_task_run(
db_sync, status="ok",
started_at=now - timedelta(hours=2),
finished_at=now - timedelta(hours=1),
)
db_sync.commit()
result = prune_task_runs.apply().get()
assert result["ok_deleted"] == 1
db_sync.expire_all()
surviving_ids = set(db_sync.execute(
select(TaskRun.id).where(TaskRun.id.in_([old_id, recent_id]))
).scalars().all())
assert surviving_ids == {recent_id}
def test_prune_task_runs_deletes_failures_older_than_7d(db_sync):
from sqlalchemy import select
from backend.app.models import TaskRun
from backend.app.tasks.maintenance import prune_task_runs
now = datetime.now(UTC)
old_id = _make_task_run(
db_sync, status="error", error_type="OldError",
started_at=now - timedelta(days=10),
finished_at=now - timedelta(days=9),
)
db_sync.commit()
result = prune_task_runs.apply().get()
assert result["failures_deleted"] >= 1
db_sync.expire_all()
surviving = db_sync.execute(
select(TaskRun.id).where(TaskRun.id == old_id)
).scalar_one_or_none()
assert surviving is None
def test_prune_task_runs_keeps_recent_failures(db_sync):
from sqlalchemy import select
from backend.app.models import TaskRun
from backend.app.tasks.maintenance import prune_task_runs
now = datetime.now(UTC)
recent_id = _make_task_run(
db_sync, status="error", error_type="RecentError",
started_at=now - timedelta(days=6),
finished_at=now - timedelta(days=5),
)
db_sync.commit()
prune_task_runs.apply().get()
db_sync.expire_all()
surviving = db_sync.execute(
select(TaskRun.id).where(TaskRun.id == recent_id)
).scalar_one_or_none()
assert surviving == recent_id
def test_prune_task_runs_never_deletes_running(db_sync):
"""Even a 30-day-old running row stays — recovery sweep is the
mechanism that flips them; prune doesn't touch in-flight."""
from sqlalchemy import select
from backend.app.models import TaskRun
from backend.app.tasks.maintenance import prune_task_runs
now = datetime.now(UTC)
ancient_id = _make_task_run(
db_sync, status="running",
started_at=now - timedelta(days=30),
)
db_sync.commit()
prune_task_runs.apply().get()
db_sync.expire_all()
surviving = db_sync.execute(
select(TaskRun.id).where(TaskRun.id == ancient_id)
).scalar_one_or_none()
assert surviving == ancient_id