arden scrape safety telemetry and polish run state UX

This commit is contained in:
Justin Visser 2026-02-19 21:59:36 +01:00
parent 110e246a1c
commit d7404abf18
33 changed files with 2074 additions and 96 deletions

View file

@ -22,6 +22,8 @@ from app.db.models import (
ScholarPublication,
)
from app.services import continuation_queue as queue_service
from app.services import run_safety as run_safety_service
from app.services import user_settings as user_settings_service
from app.services.scholar_parser import (
ParseState,
ParsedProfilePage,
@ -29,6 +31,7 @@ from app.services.scholar_parser import (
parse_profile_page,
)
from app.services.scholar_source import FetchResult, ScholarSource
from app.settings import settings
TITLE_ALNUM_RE = re.compile(r"[^a-z0-9]+")
WORD_RE = re.compile(r"[a-z0-9]+")
@ -88,6 +91,20 @@ class RunAlreadyInProgressError(RuntimeError):
"""Raised when a run lock for a user is already held by another process."""
class RunBlockedBySafetyPolicyError(RuntimeError):
def __init__(
self,
*,
code: str,
message: str,
safety_state: dict[str, Any],
) -> None:
super().__init__(message)
self.code = code
self.message = message
self.safety_state = safety_state
def _int_or_default(value: Any, default: int = 0) -> int:
try:
return int(value)
@ -134,6 +151,61 @@ class ScholarIngestionService:
alert_network_failure_threshold: int = 2,
alert_retry_scheduled_threshold: int = 3,
) -> RunExecutionSummary:
user_settings = await user_settings_service.get_or_create_settings(
db_session,
user_id=user_id,
)
now_utc = datetime.now(timezone.utc)
previous_safety_state = run_safety_service.get_safety_event_context(
user_settings,
now_utc=now_utc,
)
if run_safety_service.clear_expired_cooldown(
user_settings,
now_utc=now_utc,
):
await db_session.commit()
await db_session.refresh(user_settings)
logger.info(
"ingestion.safety_cooldown_cleared",
extra={
"event": "ingestion.safety_cooldown_cleared",
"user_id": user_id,
"reason": previous_safety_state.get("cooldown_reason"),
"cooldown_until": previous_safety_state.get("cooldown_until"),
"metric_name": "ingestion_safety_cooldown_cleared_total",
"metric_value": 1,
},
)
now_utc = datetime.now(timezone.utc)
if run_safety_service.is_cooldown_active(user_settings, now_utc=now_utc):
safety_state = run_safety_service.register_cooldown_blocked_start(
user_settings,
now_utc=now_utc,
)
await db_session.commit()
logger.warning(
"ingestion.safety_policy_blocked_run_start",
extra={
"event": "ingestion.safety_policy_blocked_run_start",
"user_id": user_id,
"trigger_type": trigger_type.value,
"reason": safety_state.get("cooldown_reason"),
"cooldown_until": safety_state.get("cooldown_until"),
"cooldown_remaining_seconds": safety_state.get("cooldown_remaining_seconds"),
"blocked_start_count": (
(safety_state.get("counters") or {}).get("blocked_start_count")
),
"metric_name": "ingestion_safety_run_start_blocked_total",
"metric_value": 1,
},
)
raise RunBlockedBySafetyPolicyError(
code="scrape_cooldown_active",
message="Scrape safety cooldown is active; run start is temporarily blocked.",
safety_state=safety_state,
)
lock_acquired = await self._try_acquire_user_lock(
db_session,
user_id=user_id,
@ -505,6 +577,8 @@ class ScholarIngestionService:
"crawl_run_id": run.id,
"blocked_failure_count": blocked_failure_count,
"threshold": bounded_blocked_threshold,
"metric_name": "ingestion_blocked_failure_threshold_exceeded_total",
"metric_value": 1,
},
)
if alert_flags["network_failure_threshold_exceeded"]:
@ -516,6 +590,8 @@ class ScholarIngestionService:
"crawl_run_id": run.id,
"network_failure_count": network_failure_count,
"threshold": bounded_network_threshold,
"metric_name": "ingestion_network_failure_threshold_exceeded_total",
"metric_value": 1,
},
)
if alert_flags["retry_scheduled_threshold_exceeded"]:
@ -527,6 +603,56 @@ class ScholarIngestionService:
"crawl_run_id": run.id,
"retries_scheduled_count": retries_scheduled_count,
"threshold": bounded_retry_threshold,
"metric_name": "ingestion_retry_scheduled_threshold_exceeded_total",
"metric_value": 1,
},
)
pre_apply_safety_state = run_safety_service.get_safety_event_context(
user_settings,
now_utc=datetime.now(timezone.utc),
)
safety_state, cooldown_trigger_reason = run_safety_service.apply_run_safety_outcome(
user_settings,
run_id=int(run.id),
blocked_failure_count=blocked_failure_count,
network_failure_count=network_failure_count,
blocked_failure_threshold=bounded_blocked_threshold,
network_failure_threshold=bounded_network_threshold,
blocked_cooldown_seconds=settings.ingestion_safety_cooldown_blocked_seconds,
network_cooldown_seconds=settings.ingestion_safety_cooldown_network_seconds,
now_utc=datetime.now(timezone.utc),
)
if cooldown_trigger_reason is not None:
logger.warning(
"ingestion.safety_cooldown_entered",
extra={
"event": "ingestion.safety_cooldown_entered",
"user_id": user_id,
"crawl_run_id": run.id,
"reason": cooldown_trigger_reason,
"blocked_failure_count": blocked_failure_count,
"network_failure_count": network_failure_count,
"blocked_failure_threshold": bounded_blocked_threshold,
"network_failure_threshold": bounded_network_threshold,
"cooldown_until": safety_state.get("cooldown_until"),
"cooldown_remaining_seconds": safety_state.get("cooldown_remaining_seconds"),
"safety_counters": safety_state.get("counters", {}),
"metric_name": "ingestion_safety_cooldown_entered_total",
"metric_value": 1,
},
)
elif pre_apply_safety_state.get("cooldown_active") and not safety_state.get("cooldown_active"):
logger.info(
"ingestion.safety_cooldown_cleared",
extra={
"event": "ingestion.safety_cooldown_cleared",
"user_id": user_id,
"crawl_run_id": run.id,
"reason": pre_apply_safety_state.get("cooldown_reason"),
"cooldown_until": pre_apply_safety_state.get("cooldown_until"),
"metric_name": "ingestion_safety_cooldown_cleared_total",
"metric_value": 1,
},
)

239
app/services/run_safety.py Normal file
View file

@ -0,0 +1,239 @@
from __future__ import annotations
from datetime import datetime, timedelta, timezone
from typing import Any
from app.db.models import UserSetting
COOLDOWN_REASON_BLOCKED_FAILURE_THRESHOLD = "blocked_failure_threshold_exceeded"
COOLDOWN_REASON_NETWORK_FAILURE_THRESHOLD = "network_failure_threshold_exceeded"
_COUNTER_CONSECUTIVE_BLOCKED_RUNS = "consecutive_blocked_runs"
_COUNTER_CONSECUTIVE_NETWORK_RUNS = "consecutive_network_runs"
_COUNTER_COOLDOWN_ENTRY_COUNT = "cooldown_entry_count"
_COUNTER_BLOCKED_START_COUNT = "blocked_start_count"
_COUNTER_LAST_BLOCKED_FAILURE_COUNT = "last_blocked_failure_count"
_COUNTER_LAST_NETWORK_FAILURE_COUNT = "last_network_failure_count"
_COUNTER_LAST_EVALUATED_RUN_ID = "last_evaluated_run_id"
def _utcnow() -> datetime:
return datetime.now(timezone.utc)
def _safe_int(value: Any, default: int = 0) -> int:
try:
return int(value)
except (TypeError, ValueError):
return default
def _safe_optional_int(value: Any) -> int | None:
if value is None:
return None
try:
return int(value)
except (TypeError, ValueError):
return None
def _normalize_datetime(value: datetime | None) -> datetime | None:
if value is None:
return None
if value.tzinfo is None:
return value.replace(tzinfo=timezone.utc)
return value.astimezone(timezone.utc)
def _state_dict(settings: UserSetting) -> dict[str, Any]:
state = settings.scrape_safety_state
if isinstance(state, dict):
return state
return {}
def _counters_from_state(settings: UserSetting) -> dict[str, Any]:
state = _state_dict(settings)
return {
_COUNTER_CONSECUTIVE_BLOCKED_RUNS: max(
0,
_safe_int(state.get(_COUNTER_CONSECUTIVE_BLOCKED_RUNS), 0),
),
_COUNTER_CONSECUTIVE_NETWORK_RUNS: max(
0,
_safe_int(state.get(_COUNTER_CONSECUTIVE_NETWORK_RUNS), 0),
),
_COUNTER_COOLDOWN_ENTRY_COUNT: max(
0,
_safe_int(state.get(_COUNTER_COOLDOWN_ENTRY_COUNT), 0),
),
_COUNTER_BLOCKED_START_COUNT: max(
0,
_safe_int(state.get(_COUNTER_BLOCKED_START_COUNT), 0),
),
_COUNTER_LAST_BLOCKED_FAILURE_COUNT: max(
0,
_safe_int(state.get(_COUNTER_LAST_BLOCKED_FAILURE_COUNT), 0),
),
_COUNTER_LAST_NETWORK_FAILURE_COUNT: max(
0,
_safe_int(state.get(_COUNTER_LAST_NETWORK_FAILURE_COUNT), 0),
),
_COUNTER_LAST_EVALUATED_RUN_ID: _safe_optional_int(
state.get(_COUNTER_LAST_EVALUATED_RUN_ID),
),
}
def _cooldown_reason_label(reason: str | None) -> str | None:
if reason == COOLDOWN_REASON_BLOCKED_FAILURE_THRESHOLD:
return "Blocked responses exceeded safety threshold"
if reason == COOLDOWN_REASON_NETWORK_FAILURE_THRESHOLD:
return "Network failures exceeded safety threshold"
return None
def _recommended_action(reason: str | None) -> str | None:
if reason == COOLDOWN_REASON_BLOCKED_FAILURE_THRESHOLD:
return (
"Google Scholar appears to be blocking requests. Wait for cooldown to expire, "
"increase request delay, and avoid repeated manual retries."
)
if reason == COOLDOWN_REASON_NETWORK_FAILURE_THRESHOLD:
return (
"Network failures crossed the threshold. Verify connectivity and retry after cooldown."
)
return None
def is_cooldown_active(
settings: UserSetting,
*,
now_utc: datetime | None = None,
) -> bool:
now = now_utc or _utcnow()
cooldown_until = _normalize_datetime(settings.scrape_cooldown_until)
if cooldown_until is None:
return False
return cooldown_until > now
def clear_expired_cooldown(
settings: UserSetting,
*,
now_utc: datetime | None = None,
) -> bool:
now = now_utc or _utcnow()
cooldown_until = _normalize_datetime(settings.scrape_cooldown_until)
if cooldown_until is None:
return False
if cooldown_until > now:
return False
settings.scrape_cooldown_until = None
settings.scrape_cooldown_reason = None
return True
def register_cooldown_blocked_start(
settings: UserSetting,
*,
now_utc: datetime | None = None,
) -> dict[str, Any]:
now = now_utc or _utcnow()
counters = _counters_from_state(settings)
counters[_COUNTER_BLOCKED_START_COUNT] = int(counters[_COUNTER_BLOCKED_START_COUNT]) + 1
settings.scrape_safety_state = counters
return get_safety_state_payload(settings, now_utc=now)
def apply_run_safety_outcome(
settings: UserSetting,
*,
run_id: int,
blocked_failure_count: int,
network_failure_count: int,
blocked_failure_threshold: int,
network_failure_threshold: int,
blocked_cooldown_seconds: int,
network_cooldown_seconds: int,
now_utc: datetime | None = None,
) -> tuple[dict[str, Any], str | None]:
now = now_utc or _utcnow()
counters = _counters_from_state(settings)
bounded_blocked_failures = max(0, int(blocked_failure_count))
bounded_network_failures = max(0, int(network_failure_count))
counters[_COUNTER_LAST_BLOCKED_FAILURE_COUNT] = bounded_blocked_failures
counters[_COUNTER_LAST_NETWORK_FAILURE_COUNT] = bounded_network_failures
counters[_COUNTER_LAST_EVALUATED_RUN_ID] = int(run_id)
counters[_COUNTER_CONSECUTIVE_BLOCKED_RUNS] = (
int(counters[_COUNTER_CONSECUTIVE_BLOCKED_RUNS]) + 1
if bounded_blocked_failures > 0
else 0
)
counters[_COUNTER_CONSECUTIVE_NETWORK_RUNS] = (
int(counters[_COUNTER_CONSECUTIVE_NETWORK_RUNS]) + 1
if bounded_network_failures > 0
else 0
)
reason: str | None = None
cooldown_seconds = 0
if bounded_blocked_failures >= max(1, int(blocked_failure_threshold)):
reason = COOLDOWN_REASON_BLOCKED_FAILURE_THRESHOLD
cooldown_seconds = max(60, int(blocked_cooldown_seconds))
elif bounded_network_failures >= max(1, int(network_failure_threshold)):
reason = COOLDOWN_REASON_NETWORK_FAILURE_THRESHOLD
cooldown_seconds = max(60, int(network_cooldown_seconds))
if reason is not None:
settings.scrape_cooldown_reason = reason
settings.scrape_cooldown_until = now + timedelta(seconds=cooldown_seconds)
counters[_COUNTER_COOLDOWN_ENTRY_COUNT] = int(counters[_COUNTER_COOLDOWN_ENTRY_COUNT]) + 1
else:
clear_expired_cooldown(settings, now_utc=now)
settings.scrape_safety_state = counters
return get_safety_state_payload(settings, now_utc=now), reason
def get_safety_state_payload(
settings: UserSetting,
*,
now_utc: datetime | None = None,
) -> dict[str, Any]:
now = now_utc or _utcnow()
cooldown_until = _normalize_datetime(settings.scrape_cooldown_until)
cooldown_active = bool(cooldown_until is not None and cooldown_until > now)
cooldown_remaining_seconds = 0
if cooldown_active and cooldown_until is not None:
cooldown_remaining_seconds = max(0, int((cooldown_until - now).total_seconds()))
reason = settings.scrape_cooldown_reason if cooldown_active else None
return {
"cooldown_active": cooldown_active,
"cooldown_reason": reason,
"cooldown_reason_label": _cooldown_reason_label(reason),
"cooldown_until": cooldown_until,
"cooldown_remaining_seconds": cooldown_remaining_seconds,
"recommended_action": _recommended_action(reason),
"counters": _counters_from_state(settings),
}
def get_safety_event_context(
settings: UserSetting,
*,
now_utc: datetime | None = None,
) -> dict[str, Any]:
payload = get_safety_state_payload(settings, now_utc=now_utc)
return {
"cooldown_active": bool(payload.get("cooldown_active")),
"cooldown_reason": payload.get("cooldown_reason"),
"cooldown_until": payload.get("cooldown_until"),
"cooldown_remaining_seconds": int(payload.get("cooldown_remaining_seconds") or 0),
"safety_counters": payload.get("counters", {}),
}

View file

@ -18,7 +18,11 @@ from app.db.models import (
)
from app.db.session import get_session_factory
from app.services import continuation_queue as queue_service
from app.services.ingestion import RunAlreadyInProgressError, ScholarIngestionService
from app.services.ingestion import (
RunAlreadyInProgressError,
RunBlockedBySafetyPolicyError,
ScholarIngestionService,
)
from app.services.scholar_source import LiveScholarSource
from app.settings import settings
@ -30,6 +34,8 @@ class _AutoRunCandidate:
user_id: int
run_interval_minutes: int
request_delay_seconds: int
cooldown_until: datetime | None
cooldown_reason: str | None
class SchedulerService:
@ -134,6 +140,9 @@ class SchedulerService:
await self._run_candidate(candidate)
async def _load_candidates(self) -> list[_AutoRunCandidate]:
if not settings.ingestion_automation_allowed:
return []
session_factory = get_session_factory()
async with session_factory() as session:
result = await session.execute(
@ -141,6 +150,8 @@ class SchedulerService:
UserSetting.user_id,
UserSetting.run_interval_minutes,
UserSetting.request_delay_seconds,
UserSetting.scrape_cooldown_until,
UserSetting.scrape_cooldown_reason,
)
.join(User, User.id == UserSetting.user_id)
.where(
@ -150,14 +161,35 @@ class SchedulerService:
.order_by(UserSetting.user_id.asc())
)
rows = result.all()
return [
_AutoRunCandidate(
user_id=int(user_id),
run_interval_minutes=int(run_interval_minutes),
request_delay_seconds=int(request_delay_seconds),
now_utc = datetime.now(timezone.utc)
candidates: list[_AutoRunCandidate] = []
for user_id, run_interval_minutes, request_delay_seconds, cooldown_until, cooldown_reason in rows:
if cooldown_until is not None and cooldown_until.tzinfo is None:
cooldown_until = cooldown_until.replace(tzinfo=timezone.utc)
if cooldown_until is not None and cooldown_until > now_utc:
logger.info(
"scheduler.run_skipped_safety_cooldown_precheck",
extra={
"event": "scheduler.run_skipped_safety_cooldown_precheck",
"user_id": int(user_id),
"reason": cooldown_reason,
"cooldown_until": cooldown_until,
"cooldown_remaining_seconds": int((cooldown_until - now_utc).total_seconds()),
"metric_name": "scheduler_run_skipped_safety_cooldown_total",
"metric_value": 1,
},
)
continue
candidates.append(
_AutoRunCandidate(
user_id=int(user_id),
run_interval_minutes=int(run_interval_minutes),
request_delay_seconds=int(request_delay_seconds),
cooldown_until=cooldown_until,
cooldown_reason=(str(cooldown_reason).strip() if cooldown_reason else None),
)
)
for user_id, run_interval_minutes, request_delay_seconds in rows
]
return candidates
async def _is_due(self, candidate: _AutoRunCandidate, *, now: datetime) -> bool:
session_factory = get_session_factory()
@ -210,6 +242,21 @@ class SchedulerService:
},
)
return
except RunBlockedBySafetyPolicyError as exc:
await session.rollback()
logger.info(
"scheduler.run_skipped_safety_cooldown",
extra={
"event": "scheduler.run_skipped_safety_cooldown",
"user_id": candidate.user_id,
"reason": exc.safety_state.get("cooldown_reason"),
"cooldown_until": exc.safety_state.get("cooldown_until"),
"cooldown_remaining_seconds": exc.safety_state.get("cooldown_remaining_seconds"),
"metric_name": "scheduler_run_skipped_safety_cooldown_total",
"metric_value": 1,
},
)
return
except Exception:
await session.rollback()
logger.exception(
@ -354,6 +401,34 @@ class SchedulerService:
},
)
return
except RunBlockedBySafetyPolicyError as exc:
await session.rollback()
cooldown_remaining_seconds = max(
self._tick_seconds,
int(exc.safety_state.get("cooldown_remaining_seconds") or 0),
)
async with session_factory() as recovery_session:
await queue_service.reschedule_job(
recovery_session,
job_id=job.id,
delay_seconds=max(self._tick_seconds, cooldown_remaining_seconds),
reason="scrape_safety_cooldown",
error=str(exc.message),
)
await recovery_session.commit()
logger.info(
"scheduler.queue_item_deferred_safety_cooldown",
extra={
"event": "scheduler.queue_item_deferred_safety_cooldown",
"queue_item_id": job.id,
"user_id": job.user_id,
"reason": exc.safety_state.get("cooldown_reason"),
"cooldown_remaining_seconds": cooldown_remaining_seconds,
"metric_name": "scheduler_queue_item_deferred_safety_cooldown_total",
"metric_value": 1,
},
)
return
except Exception as exc:
await session.rollback()
async with session_factory() as recovery_session:

View file

@ -33,25 +33,49 @@ REQUIRED_NAV_PAGES = (
NAV_PAGE_SETTINGS,
)
DEFAULT_NAV_VISIBLE_PAGES = list(ALLOWED_NAV_PAGES)
HARD_MIN_RUN_INTERVAL_MINUTES = 15
HARD_MIN_REQUEST_DELAY_SECONDS = 2
def parse_run_interval_minutes(value: str) -> int:
def resolve_run_interval_minimum(configured_minimum: int | None) -> int:
try:
parsed = int(configured_minimum) if configured_minimum is not None else HARD_MIN_RUN_INTERVAL_MINUTES
except (TypeError, ValueError):
parsed = HARD_MIN_RUN_INTERVAL_MINUTES
return max(HARD_MIN_RUN_INTERVAL_MINUTES, parsed)
def resolve_request_delay_minimum(configured_minimum: int | None) -> int:
try:
parsed = int(configured_minimum) if configured_minimum is not None else HARD_MIN_REQUEST_DELAY_SECONDS
except (TypeError, ValueError):
parsed = HARD_MIN_REQUEST_DELAY_SECONDS
return max(HARD_MIN_REQUEST_DELAY_SECONDS, parsed)
def parse_run_interval_minutes(value: str, *, minimum: int = HARD_MIN_RUN_INTERVAL_MINUTES) -> int:
try:
parsed = int(value)
except ValueError as exc:
raise UserSettingsServiceError("Check interval must be a whole number.") from exc
if parsed < 15:
raise UserSettingsServiceError("Check interval must be at least 15 minutes.")
effective_minimum = resolve_run_interval_minimum(minimum)
if parsed < effective_minimum:
raise UserSettingsServiceError(
f"Check interval must be at least {effective_minimum} minutes."
)
return parsed
def parse_request_delay_seconds(value: str) -> int:
def parse_request_delay_seconds(value: str, *, minimum: int = HARD_MIN_REQUEST_DELAY_SECONDS) -> int:
try:
parsed = int(value)
except ValueError as exc:
raise UserSettingsServiceError("Request delay must be a whole number.") from exc
if parsed < 2:
raise UserSettingsServiceError("Request delay must be at least 2 seconds.")
effective_minimum = resolve_request_delay_minimum(minimum)
if parsed < effective_minimum:
raise UserSettingsServiceError(
f"Request delay must be at least {effective_minimum} seconds."
)
return parsed