Lukas
52f237d5d4
CRITICAL FIX: Background tasks (especially blocklist_import) crashed mid-execution, leaving partial state. On retry, the same bans were applied again, causing duplicates. Solution: Content-hash based operation tracking for blocklist imports: - Added import_runs table (migration 6) to track operations by source + content hash - Before banning, check if this exact content has already been imported - If completed: skip banning (already done), optionally re-warm cache - If new or failed: proceed with ban and mark as completed or failed Changes: - Database: Migration 6 adds import_runs table with operation state tracking - Model: Added ImportRunEntry for import run records - Repository: New import_run_repo module with CRUD operations - Workflow: Updated blocklist_import_workflow to check operation history before banning - Dependencies: Registered import_run_repo for dependency injection - Tests: Added test_import_source_idempotent_on_retry and test_import_source_different_content_not_reused - Documentation: Added Task Idempotency section to Backend-Development.md Verification: - All 7 import tests pass (5 existing + 2 new idempotency tests) - Type checking: mypy --strict ✅ - Linting: ruff ✅ - No API changes, backwards compatible via automatic migration Fixes: Background tasks not idempotent #CRITICAL Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
145 lines
5.6 KiB
Python
145 lines
5.6 KiB
Python
"""Tests for timeout protection utilities for background tasks.
|
|
|
|
Validates that :func:`~app.tasks.timeout_utils.run_with_timeout` correctly
|
|
enforces timeouts on async tasks and logs appropriate warnings.
|
|
"""
|
|
|
|
from __future__ import annotations
|
|
|
|
import asyncio
|
|
from unittest.mock import AsyncMock, patch
|
|
|
|
import pytest
|
|
|
|
|
|
class TestRunWithTimeout:
|
|
"""Tests for :func:`~app.tasks.timeout_utils.run_with_timeout`."""
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_run_with_timeout_completes_quickly(self) -> None:
|
|
"""``run_with_timeout`` must complete and return the result when task finishes quickly."""
|
|
from app.tasks.timeout_utils import run_with_timeout
|
|
|
|
async def _quick_task() -> str:
|
|
return "success"
|
|
|
|
result = await run_with_timeout("test_task", _quick_task(), timeout_seconds=10)
|
|
assert result == "success"
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_run_with_timeout_raises_timeout_error(self) -> None:
|
|
"""``run_with_timeout`` must raise TimeoutError when task exceeds timeout."""
|
|
from app.tasks.timeout_utils import run_with_timeout
|
|
|
|
async def _slow_task() -> None:
|
|
await asyncio.sleep(5)
|
|
|
|
with pytest.raises(TimeoutError):
|
|
await run_with_timeout("slow_task", _slow_task(), timeout_seconds=0.1)
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_run_with_timeout_logs_timeout_event(self) -> None:
|
|
"""``run_with_timeout`` must log a warning when timeout occurs."""
|
|
from app.tasks.timeout_utils import run_with_timeout
|
|
|
|
async def _slow_task() -> None:
|
|
await asyncio.sleep(5)
|
|
|
|
with patch("app.tasks.timeout_utils.log") as mock_log:
|
|
with pytest.raises(TimeoutError):
|
|
await run_with_timeout("slow_task", _slow_task(), timeout_seconds=0.1)
|
|
|
|
# Verify timeout was logged
|
|
timeout_calls = [
|
|
c for c in mock_log.warning.call_args_list if c[0][0] == "task_timeout"
|
|
]
|
|
assert len(timeout_calls) == 1
|
|
call_kwargs = timeout_calls[0][1]
|
|
assert call_kwargs["task_name"] == "slow_task"
|
|
assert call_kwargs["timeout_seconds"] == 0.1
|
|
assert call_kwargs["elapsed_seconds"] >= 0.1
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_run_with_timeout_logs_approaching_timeout(self) -> None:
|
|
"""``run_with_timeout`` must log warning when task uses >80% of timeout."""
|
|
from app.tasks.timeout_utils import run_with_timeout
|
|
|
|
async def _medium_task() -> None:
|
|
await asyncio.sleep(0.25)
|
|
|
|
with patch("app.tasks.timeout_utils.log") as mock_log:
|
|
await run_with_timeout("medium_task", _medium_task(), timeout_seconds=0.3)
|
|
|
|
# Verify approaching timeout warning was logged (task used >80% of timeout)
|
|
approaching_calls = [
|
|
c
|
|
for c in mock_log.warning.call_args_list
|
|
if c[0][0] == "task_approaching_timeout"
|
|
]
|
|
assert len(approaching_calls) == 1
|
|
call_kwargs = approaching_calls[0][1]
|
|
assert call_kwargs["task_name"] == "medium_task"
|
|
assert call_kwargs["timeout_seconds"] == 0.3
|
|
assert call_kwargs["usage_percent"] > 80
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_run_with_timeout_no_warning_when_well_under_timeout(self) -> None:
|
|
"""``run_with_timeout`` must not log warning when task completes well before timeout."""
|
|
from app.tasks.timeout_utils import run_with_timeout
|
|
|
|
async def _quick_task() -> None:
|
|
await asyncio.sleep(0.01)
|
|
|
|
with patch("app.tasks.timeout_utils.log") as mock_log:
|
|
await run_with_timeout("quick_task", _quick_task(), timeout_seconds=1.0)
|
|
|
|
# Verify no approaching timeout warning was logged
|
|
approaching_calls = [
|
|
c
|
|
for c in mock_log.warning.call_args_list
|
|
if c[0][0] == "task_approaching_timeout"
|
|
]
|
|
assert len(approaching_calls) == 0
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_run_with_timeout_logs_elapsed_time(self) -> None:
|
|
"""``run_with_timeout`` must include elapsed time in timeout log."""
|
|
from app.tasks.timeout_utils import run_with_timeout
|
|
|
|
async def _slow_task() -> None:
|
|
await asyncio.sleep(0.2)
|
|
|
|
with patch("app.tasks.timeout_utils.log") as mock_log:
|
|
with pytest.raises(TimeoutError):
|
|
await run_with_timeout("slow_task", _slow_task(), timeout_seconds=0.1)
|
|
|
|
timeout_calls = [
|
|
c for c in mock_log.warning.call_args_list if c[0][0] == "task_timeout"
|
|
]
|
|
call_kwargs = timeout_calls[0][1]
|
|
assert "elapsed_seconds" in call_kwargs
|
|
assert call_kwargs["elapsed_seconds"] >= 0.1
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_run_with_timeout_returns_correct_type(self) -> None:
|
|
"""``run_with_timeout`` must preserve the return type of the coroutine."""
|
|
from app.tasks.timeout_utils import run_with_timeout
|
|
|
|
async def _task_returns_int() -> int:
|
|
return 42
|
|
|
|
result = await run_with_timeout("int_task", _task_returns_int(), timeout_seconds=10)
|
|
assert isinstance(result, int)
|
|
assert result == 42
|
|
|
|
@pytest.mark.asyncio
|
|
async def test_run_with_timeout_task_exception_propagates(self) -> None:
|
|
"""``run_with_timeout`` must propagate exceptions from the task (not timeout)."""
|
|
from app.tasks.timeout_utils import run_with_timeout
|
|
|
|
async def _failing_task() -> None:
|
|
raise ValueError("Task failed")
|
|
|
|
with pytest.raises(ValueError, match="Task failed"):
|
|
await run_with_timeout("failing_task", _failing_task(), timeout_seconds=10)
|