utils/logging.py

"""
Structured logging with execution context.

Every execution (a job, a provider invocation, a retry attempt) is
given an `ExecutionContext` that binds the following fields into every
log line produced inside that context:

    execution_id   — UUID for the top-level job
    provider_id    — name of the provider being invoked (or "-")
    retry_count    — how many retries have occurred for this attempt
    status         — "started" | "success" | "failed" | "retried"

Implementation: loguru's `contextualize()` binds dict keys into the
`extra` dict of every record created within the context.  We layer a
small wrapper on top so callers don't have to remember the keys.
"""

from __future__ import annotations

import sys
import uuid
from contextlib import contextmanager
from contextvars import ContextVar
from typing import Any, Iterator, Optional

from loguru import logger

from config.settings import Settings


# Context vars for in-process propagation (e.g. into async tasks)
_execution_id: ContextVar[str] = ContextVar("execution_id", default="-")
_provider_id: ContextVar[str] = ContextVar("provider_id", default="-")
_retry_count: ContextVar[int] = ContextVar("retry_count", default=0)
_status: ContextVar[str] = ContextVar("status", default="started")


def setup_logging(settings: Settings) -> None:
    """Configure loguru sinks.  Call once at app startup."""
    logger.remove()

    if settings.log_json:
        fmt = (
            '{{"timestamp":"{time:YYYY-MM-DDTHH:mm:ss.SSSZ}",'
            '"level":"{level}",'
            '"execution_id":"{extra[execution_id]}",'
            '"provider_id":"{extra[provider_id]}",'
            '"retry_count":{extra[retry_count]},'
            '"status":"{extra[status]}",'
            '"message":"{message}"}}'
        )
    else:
        fmt = (
            "{time:YYYY-MM-DD HH:mm:ss.SSS} | {level: <8} | "
            "eid={extra[execution_id]} | pid={extra[provider_id]} | "
            "retry={extra[retry_count]} | status={extra[status]} | "
            "{message}"
        )

    logger.configure(
        extra={
            "execution_id": "-",
            "provider_id": "-",
            "retry_count": 0,
            "status": "started",
        }
    )
    logger.add(sys.stderr, format=fmt, level=settings.log_level, backtrace=True, diagnose=False)


def new_execution_id() -> str:
    """Generate a fresh execution id."""
    return uuid.uuid4().hex[:12]


@contextmanager
def execution_context(
    execution_id: Optional[str] = None,
    provider_id: str = "-",
    retry_count: int = 0,
    status: str = "started",
) -> Iterator[dict]:
    """Bind execution context to every log line produced inside the block.

    Usage:
        with execution_context(provider_id="haar") as ctx:
            ctx["status"] = "running"
            logger.info("detecting faces")
            ctx["status"] = "success"
    """
    eid = execution_id or new_execution_id()
    ctx = {
        "execution_id": eid,
        "provider_id": provider_id,
        "retry_count": retry_count,
        "status": status,
    }
    eid_token = _execution_id.set(eid)
    pid_token = _provider_id.set(provider_id)
    rc_token = _retry_count.set(retry_count)
    st_token = _status.set(status)
    with logger.contextualize(**ctx):
        try:
            yield ctx
        finally:
            _execution_id.reset(eid_token)
            _provider_id.reset(pid_token)
            _retry_count.reset(rc_token)
            _status.reset(st_token)


def current_execution_id() -> str:
    return _execution_id.get()


def current_provider_id() -> str:
    return _provider_id.get()


__all__ = [
    "setup_logging",
    "new_execution_id",
    "execution_context",
    "current_execution_id",
    "current_provider_id",
    "logger",
]