iaai-parser/iaai_scraper/worker/celery_app.py

# Инициализация Celery-приложения и периодических задач.

import json
import logging
import os
import time

from celery import Celery
from celery.signals import worker_process_init, worker_ready, setup_logging as celery_setup_logging
from redis import Redis

from ..core.config import settings
from ..core.logs import setup_logging

logger = logging.getLogger("iaai_scraper.worker.celery_app")
STARTUP_SYNC_DISPATCH_KEY = "iaai:state:startup_sync_dispatched"
IAAI_SYNC_QUEUE = "iaai_sync"
PROGRESS_KEY_PREFIX = "iaai:state:task_progress:"
SYNC_LISTING_LOCK_KEY = "iaai:locks:sync_listing"
SYNC_FULL_SCAN_DONE_KEY = "iaai:state:sync_full_scan_done"
SYNC_LAST_COMPLETED_AT_KEY = "iaai:state:sync_listing_last_completed_at"


def _env_bool(name: str, default: bool) -> bool:
    raw = os.getenv(name, "true" if default else "false").strip().lower()
    return raw in {"1", "true", "yes", "on"}


def _has_fresh_active_progress(redis_client: Redis, *, max_age_seconds: int = 180) -> bool:
    now = int(time.time())
    try:
        for raw_key in redis_client.scan_iter(f"{PROGRESS_KEY_PREFIX}*"):
            payload = redis_client.get(raw_key)
            if not payload:
                continue
            try:
                progress = json.loads(payload)
            except (TypeError, ValueError):
                continue
            ts = int(progress.get("ts") or 0)
            stage = str(progress.get("stage") or "")
            if ts > 0 and now - ts <= max_age_seconds and stage not in {"segment_done", "sync_done", "failed"}:
                return True
    except Exception:
        logger.warning("Failed to inspect startup progress keys", exc_info=True)
    return False


def _seconds_until_next_allowed_sync(redis_client: Redis) -> int:
    """Запрещает новый автозапуск раньше чем через интервал beat после завершения полного run."""
    min_interval = max(0, int(settings.celery.beat_sync_interval_minutes * 60))
    if min_interval <= 0:
        return 0
    try:
        full_done = str(redis_client.get(SYNC_FULL_SCAN_DONE_KEY) or "").strip().lower() in {"1", "true", "yes", "on"}
        if not full_done:
            return 0
        completed_raw = redis_client.get(SYNC_LAST_COMPLETED_AT_KEY)
        if not completed_raw:
            return 0
        completed_at = int(float(completed_raw))
    except Exception:
        logger.warning("Failed to inspect last sync completion timestamp", exc_info=True)
        return 0
    elapsed = int(time.time()) - completed_at
    return max(0, min_interval - elapsed)


@celery_setup_logging.connect
def _configure_logging(loglevel=None, **kwargs):
    # Перехватываем логирование Celery и пишем только в stderr (Docker logs).
    level = settings.log_level if settings.log_level else "INFO"
    setup_logging(level, None)


@worker_process_init.connect
def _on_worker_process_init(**kwargs):
    # Повторно настраиваем логирование в каждом дочернем prefork-процессе,
    # чтобы StreamHandler(stderr) корректно работал после fork.
    level = settings.log_level if settings.log_level else "INFO"
    setup_logging(level, None)


def _broker_url() -> str:
    return settings.celery.broker_url or settings.redis.url


def _result_backend() -> str:
    return settings.celery.result_backend or settings.redis.url


celery_app = Celery(
    "iaai_scraper",
    broker=_broker_url(),
    backend=_result_backend(),
)

# Auto-clamp: если hard limit слишком далёк от soft (> soft + 120),
# ограничиваем, чтобы зависший worker не жил вечно.
_soft = settings.celery.task_soft_time_limit
_hard = settings.celery.task_time_limit
_max_hard = _soft + 120 if _soft else _hard
if _hard > _max_hard:
    logger.info(
        "CELERY_TASK_TIME_LIMIT=%d too far from CELERY_TASK_SOFT_TIME_LIMIT=%d; "
        "clamping hard limit to %d",
        _hard, _soft, _max_hard,
    )
    _hard = _max_hard

celery_app.conf.update(
    task_serializer="json",
    accept_content=["json"],
    result_serializer="json",
    timezone="UTC",
    enable_utc=True,
    task_soft_time_limit=_soft,
    task_time_limit=_hard,
    task_acks_late=True,
    task_reject_on_worker_lost=True,
    task_track_started=True,
    worker_concurrency=settings.celery.worker_concurrency,
    worker_max_tasks_per_child=settings.celery.worker_max_tasks_per_child,
    worker_pool=settings.celery.worker_pool,
    worker_prefetch_multiplier=1,
    broker_connection_retry_on_startup=True,
    broker_transport_options={
        "visibility_timeout": settings.celery.broker_visibility_timeout,
    },
    result_expires=86400,
    worker_redirect_stdouts=False,
    worker_hijack_root_logger=False,
    beat_schedule={
        "periodic-sync-listing": {
            "task": "iaai.sync_cars_feed",
            "schedule": settings.celery.beat_sync_interval_minutes * 60.0,
            "args": (),
            "kwargs": {"limit": settings.celery.beat_sync_limit, "only_new": True},
            "options": {
                "queue": IAAI_SYNC_QUEUE,
                "expires": settings.celery.beat_sync_interval_minutes * 60.0,
                "headers": {"iaai_beat_task": True},
            },
        }
    },
    task_routes={
        "iaai.sync_cars_feed": {"queue": IAAI_SYNC_QUEUE},
        "iaai_scraper.worker.tasks.*": {"queue": IAAI_SYNC_QUEUE},
    },
)

celery_app.autodiscover_tasks(["iaai_scraper.worker"])


@worker_ready.connect
def _on_worker_ready(**kwargs):
    """При старте worker отправляем первый sync_listing, если очередь пуста."""
    if not _env_bool("IAAI_STARTUP_SYNC_ENABLED", True):
        logger.info("Worker ready: startup sync dispatch disabled by IAAI_STARTUP_SYNC_ENABLED")
        return

    redis_client = None
    try:
        redis_client = Redis.from_url(
            settings.redis.url,
            decode_responses=True,
            socket_connect_timeout=settings.redis.socket_connect_timeout_seconds,
            socket_timeout=settings.redis.socket_timeout_seconds,
            health_check_interval=settings.redis.health_check_interval_seconds,
            retry_on_timeout=True,
        )

        has_fresh_progress = _has_fresh_active_progress(redis_client)
        next_allowed_delay = _seconds_until_next_allowed_sync(redis_client)
        if next_allowed_delay > 0:
            logger.info(
                "Worker ready: last full sync finished recently; next auto sync allowed in %ss, skip startup dispatch",
                next_allowed_delay,
            )
            return

        for stale_key in (SYNC_LISTING_LOCK_KEY,):
            try:
                ttl = redis_client.ttl(stale_key)
                if ttl is not None and ttl != -2 and not has_fresh_progress:
                    redis_client.delete(stale_key)
                    logger.info("Cleared stale lock on startup: %s (ttl was %s)", stale_key, ttl)
                elif ttl is not None and ttl != -2:
                    logger.info("Keeping sync lock on startup because fresh active progress exists: %s (ttl=%s)", stale_key, ttl)
            except Exception:
                logger.warning("Failed to inspect stale lock %s on startup", stale_key, exc_info=True)

        try:
            queue_len = int(redis_client.llen(IAAI_SYNC_QUEUE) or 0)
        except Exception:
            queue_len = 0
        if queue_len > 0:
            logger.info("Worker ready: iaai_sync queue already has %d task(s); skip startup dispatch", queue_len)
            return

        should_dispatch = bool(redis_client.set(STARTUP_SYNC_DISPATCH_KEY, "1", nx=True, ex=600))
        if not should_dispatch and not has_fresh_progress:
            redis_client.delete(STARTUP_SYNC_DISPATCH_KEY)
            should_dispatch = bool(redis_client.set(STARTUP_SYNC_DISPATCH_KEY, "1", nx=True, ex=600))
            if should_dispatch:
                logger.info("Worker ready: stale startup dedupe key ignored because queue is empty and no fresh active progress exists")
    except Exception:
        logger.warning("Worker ready startup sync dedupe check failed; skipping immediate dispatch", exc_info=True)
        return
    finally:
        if redis_client is not None:
            try:
                redis_client.close()
            except Exception:
                pass

    if not should_dispatch:
        logger.info("Worker ready immediate sync already dispatched recently; skipping duplicate enqueue")
        return

    logger.info("Worker ready — dispatching initial sync_listing task")
    celery_app.send_task(
        "iaai.sync_cars_feed",
        kwargs={"limit": settings.celery.beat_sync_limit, "only_new": False},
        queue=IAAI_SYNC_QUEUE,
        expires=settings.celery.beat_sync_interval_minutes * 60.0,
    )