mostovik-backend/src/apps/core/logging.py

"""
Настройка структурированного логирования.

Предоставляет JSON-форматтер и утилиты для production логов.
"""

import json
import logging
import traceback
from datetime import UTC, datetime
from typing import Any

from apps.core.middleware import get_request_id


class JSONFormatter(logging.Formatter):
    """
    Форматтер логов в JSON формате.

    Формирует структурированные логи для удобного парсинга
    в системах мониторинга (ELK, Grafana Loki, etc.).

    Пример вывода:
        {
            "timestamp": "2024-01-15T10:30:45.123456Z",
            "level": "INFO",
            "logger": "apps.user.services",
            "message": "User created",
            "request_id": "abc-123",
            "user_id": 42,
            "extra": {"email": "user@example.com"}
        }
    """

    def format(self, record: logging.LogRecord) -> str:
        """Форматирует запись лога в JSON."""
        log_data: dict[str, Any] = {
            "timestamp": datetime.now(UTC).isoformat(),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }

        # Добавляем request_id если доступен
        request_id = get_request_id()
        if request_id:
            log_data["request_id"] = request_id

        # Добавляем информацию о месте вызова
        log_data["location"] = {
            "file": record.filename,
            "line": record.lineno,
            "function": record.funcName,
        }

        # Добавляем extra данные
        extra_fields = {}
        for key, value in record.__dict__.items():
            if key not in {
                "name",
                "msg",
                "args",
                "created",
                "filename",
                "funcName",
                "levelname",
                "levelno",
                "lineno",
                "module",
                "msecs",
                "pathname",
                "process",
                "processName",
                "relativeCreated",
                "stack_info",
                "exc_info",
                "exc_text",
                "thread",
                "threadName",
                "message",
                "taskName",
            }:
                extra_fields[key] = value

        if extra_fields:
            log_data["extra"] = extra_fields

        # Добавляем информацию об исключении
        if record.exc_info:
            log_data["exception"] = {
                "type": record.exc_info[0].__name__ if record.exc_info[0] else None,
                "message": str(record.exc_info[1]) if record.exc_info[1] else None,
                "traceback": traceback.format_exception(*record.exc_info),
            }

        return json.dumps(log_data, ensure_ascii=False, default=str)


class ContextLogger:
    """
    Логгер с автоматическим добавлением контекста.

    Пример использования:
        logger = ContextLogger(__name__)
        logger.set_context(user_id=42, action="login")
        logger.info("User logged in")  # Автоматически добавит user_id и action
    """

    def __init__(self, name: str):
        self._logger = logging.getLogger(name)
        self._context: dict[str, Any] = {}

    def set_context(self, **kwargs: Any) -> None:
        """Устанавливает контекст для всех последующих логов."""
        self._context.update(kwargs)

    def clear_context(self) -> None:
        """Очищает контекст."""
        self._context.clear()

    def _log(
        self,
        level: int,
        message: str,
        *args: Any,
        exc_info: bool = False,
        **kwargs: Any,
    ) -> None:
        """Логирует сообщение с контекстом."""
        extra = {**self._context, **kwargs.pop("extra", {})}
        self._logger.log(
            level, message, *args, extra=extra, exc_info=exc_info, **kwargs
        )

    def debug(self, message: str, *args: Any, **kwargs: Any) -> None:
        """Логирует DEBUG сообщение."""
        self._log(logging.DEBUG, message, *args, **kwargs)

    def info(self, message: str, *args: Any, **kwargs: Any) -> None:
        """Логирует INFO сообщение."""
        self._log(logging.INFO, message, *args, **kwargs)

    def warning(self, message: str, *args: Any, **kwargs: Any) -> None:
        """Логирует WARNING сообщение."""
        self._log(logging.WARNING, message, *args, **kwargs)

    def error(
        self, message: str, *args: Any, exc_info: bool = True, **kwargs: Any
    ) -> None:
        """Логирует ERROR сообщение."""
        self._log(logging.ERROR, message, *args, exc_info=exc_info, **kwargs)

    def exception(self, message: str, *args: Any, **kwargs: Any) -> None:
        """Логирует исключение."""
        self._log(logging.ERROR, message, *args, exc_info=True, **kwargs)


def get_json_logging_config(
    log_level: str = "INFO",
    log_file: str | None = None,
) -> dict[str, Any]:
    """
    Возвращает конфигурацию логирования для production.

    Args:
        log_level: Уровень логирования
        log_file: Путь к файлу логов (опционально)

    Пример использования в settings.py:
        from apps.core.logging import get_json_logging_config

        LOGGING = get_json_logging_config(
            log_level="INFO",
            log_file="/var/log/app/app.log",
        )
    """
    handlers = {
        "console": {
            "class": "logging.StreamHandler",
            "formatter": "json",
        },
    }

    root_handlers = ["console"]

    if log_file:
        handlers["file"] = {
            "class": "logging.handlers.RotatingFileHandler",
            "filename": log_file,
            "maxBytes": 10 * 1024 * 1024,  # 10 MB
            "backupCount": 5,
            "formatter": "json",
        }
        root_handlers.append("file")

    return {
        "version": 1,
        "disable_existing_loggers": False,
        "formatters": {
            "json": {
                "()": "apps.core.logging.JSONFormatter",
            },
            "standard": {
                "format": "%(asctime)s [%(levelname)s] %(name)s: %(message)s",
            },
        },
        "handlers": handlers,
        "root": {
            "handlers": root_handlers,
            "level": log_level,
        },
        "loggers": {
            "django": {
                "handlers": root_handlers,
                "level": "WARNING",
                "propagate": False,
            },
            "django.request": {
                "handlers": root_handlers,
                "level": "WARNING",
                "propagate": False,
            },
            "celery": {
                "handlers": root_handlers,
                "level": "INFO",
                "propagate": False,
            },
            "apps": {
                "handlers": root_handlers,
                "level": log_level,
                "propagate": False,
            },
        },
    }


def log_request(
    logger: logging.Logger,
    request: Any,
    response: Any | None = None,
    duration_ms: float | None = None,
) -> None:
    """
    Логирует HTTP запрос/ответ.

    Пример использования:
        from apps.core.logging import log_request

        def my_middleware(get_response):
            def middleware(request):
                start = time.time()
                response = get_response(request)
                duration = (time.time() - start) * 1000
                log_request(logger, request, response, duration)
                return response
            return middleware
    """
    extra: dict[str, Any] = {
        "method": request.method,
        "path": request.path,
        "user_id": getattr(request.user, "id", None)
        if hasattr(request, "user")
        else None,
    }

    if response:
        extra["status_code"] = response.status_code

    if duration_ms:
        extra["duration_ms"] = round(duration_ms, 2)

    request_id = get_request_id()
    if request_id:
        extra["request_id"] = request_id

    message = f"{request.method} {request.path}"
    if response:
        message += f" -> {response.status_code}"
    if duration_ms:
        message += f" ({duration_ms:.0f}ms)"

    if response and response.status_code >= 500:
        logger.error(message, extra=extra)
    elif response and response.status_code >= 400:
        logger.warning(message, extra=extra)
    else:
        logger.info(message, extra=extra)