Как выбрать стратегию логирования в Python-сервисе: уровни, контекст и correlation-id

Логирование в продакшене — это не “добавим logger.info везде, а дальше разберёмся”. В зрелых системах оно выполняет сразу несколько функций: даёт наблюдаемость (observability), ускоряет диагностику инцидентов, поддерживает пост-мортем анализ и формирует данные для алертов. Но качество логов определяется не количеством строк, а стратегией: что логировать, как структурировать, как добавлять контекст, как связывать события во времени и как безопасно обращаться с персональными данными.

Ниже разберём, как выстроить логирование в Python-сервисе так, чтобы оно было читабельным для инженера и пригодным для автоматизированного анализа. Разговор пойдёт про уровни, контекст запроса, correlation-id, PII и полезные поля для трассировок и алертов.

1) Что считать хорошей стратегией логирования

Хорошая стратегия отвечает на три вопроса:

1. Цель: для чего именно нужны логи в этой системе?

   • диагностика ошибок,
   • аудит действий,
   • анализ производительности (latency),
   • подтверждение сценариев (workflow),
   • поиск аномалий.

2. Релевантность и стоимость: какие логи дают максимум пользы при минимальной цене (CPU, IO, стоимость хранения, шум)?

   • слишком подробные логи быстро превращаются в “мусорные джунгли”,
   • слишком редкие — не позволяют восстановить картину при инциденте.

3. Корреляция: как связать множество событий в один “след” запроса?

   • нужен идентификатор (например, correlation-id),
   • нужна структура данных и единый формат.

С точки зрения практики, хорошая стратегия почти всегда сводится к комбинации:

• структурированных логов (JSON),
• стабильных полей (request_id, user_id (если можно), route, status_code и т.д.),
• правил логирования (когда INFO, когда DEBUG, когда WARNING/ERROR),
• контекстного логгера (чтобы не передавать параметры в каждую функцию вручную),
• корректной работы с исключениями и stack traces,
• PII-safe подхода (маскирование/редакция/отказ от логирования).

2) Уровни логирования: где INFO, WARNING и ERROR действительно полезны

В Python обычно используют стандартные уровни: DEBUG, INFO, WARNING, ERROR, CRITICAL. Проблема в том, что многие команды превращают все уровни в “INFO обо всём”. Чтобы этого избежать, определите правила для уровней заранее.

2.1 DEBUG: для локальной диагностики и временных расследований

DEBUG — это уровень для деталей, которые обычно не нужны в проде постоянно, но полезны при инциденте.

Логировать DEBUG имеет смысл, если:

• вы включаете DEBUG динамически (через конфиг или feature flag),
• логи не содержат PII,
• объём предсказуем или ограничен (например, только для одной трассировки по correlation-id).

Примеры DEBUG-сообщений:

• детали парсинга запроса,
• результаты внутренних вычислений (без секретов и PII),
• тайминги внутренних шагов при диагностике.

2.2 INFO: бизнес-события и значимые “вехи” запроса

INFO — это то, что вы ожидаете видеть в проде, чтобы понимать “что происходило”.

Хороший INFO в проде — это:

• завершение запроса с итогом (успех/ошибка) и метриками,
• переходы по workflow (например, “заказ создан”, “платёж отклонён”),
• запуск/останов задач по расписанию (если это часть бизнес-логики),
• подтверждение обработки асинхронных сообщений.

Одна из рабочих практик: логировать один INFO на запрос (или на сообщение в очереди) вместо тысячи строк внутри обработчика.

2.3 WARNING: проблемы, которые не ломают запрос, но требуют внимания

WARNING — это потенциальные проблемы:

• таймауты на внешних API с fallback,
• деградация качества (например, “используем устаревший кеш”),
• необычные, но допустимые состояния (например, “не нашли необязательное поле”).

WARNING должно:

• быть агрегируемым для алертов,
• содержать контекст, по которому можно понять причину,
• не превращаться в шум.

Если WARNING слишком часто — пересмотрите границу: может, это должен быть INFO (если “норма”) или ERROR (если “поломка”).

2.4 ERROR: сбой операции, из которой не удаётся восстановиться

ERROR — для ошибок, которые привели к:

• возвращению 4xx/5xx,
• отклонению сообщения,
• невозможности обработать запрос корректно.

Важный нюанс: не каждая исключительная ситуация должна быть ERROR. Иногда это “ожидаемый” сценарий (например, валидация формы). В этом случае логировать стоит хотя бы WARNING/INFO (в зависимости от требований), но не обязательно ERROR.

2.5 CRITICAL: то, что означает системный отказ

CRITICAL — когда система в целом может быть неработоспособна:

• потеря подключения к хранилищу при старте,
• массовые отказы (ошибки инфраструктуры),
• невозможность поднять критические компоненты.

Чаще CRITICAL пишут редко, но это полезно для “сигнализации сверху”.

3) Что логировать, а что нет: полезный шаблон

Главный принцип: лог — это не сериализация “всего, что есть в объекте”. Выберите набор полей, который помогает ответить на вопросы:

• Что произошло?
• Где?
• Когда?
• С каким запросом/сообщением связано?
• Каков результат (статус) и сколько заняло?
• Есть ли ошибка, и какая именно?
• Какие ключевые параметры (не PII) участвуют?

3.1 Принципы “что логировать”

Обычно логируют:

1. Идентификаторы корреляции и маршрута

   • correlation_id
   • trace_id (если есть OpenTelemetry)
   • service, environment
   • route/handler/operation

2. Контекст запроса/сообщения

   • http.method, path или route_name
   • status_code
   • client_ip (но аккуратно с политикой безопасности)
   • user_id если это не PII в вашем контексте (и соблюдены правила хранения)
   • tenant_id (если мультиарендность)

3. Временные метрики

   • duration_ms
   • таймауты внешних вызовов

4. Ошибки

   • класс/тип ошибки (error_type)
   • человеко-читаемое сообщение (error_message, обычно без деталей PII)
   • stack trace — в виде exc_info (но осторожно с объёмом)

5. Системные параметры

   • retry_count (для ретраев)
   • queue_name, message_id для асинхронщины

3.2 Принципы “что не логировать”

Категорически не стоит логировать без специальной политики:

• пароли, токены, секреты,
• полный текст авторизационных заголовков,
• номера банковских карт,
• персональные данные (PII): email, телефон, паспорт и т.д.,
• пользовательские сообщения “как есть” (особенно если они могут содержать персональные данные),
• большие payload’ы (тела запросов/ответов) — лучше логировать размер и факт успешной/ошибочной обработки.

Если нужно отладить проблему, лучше логировать:

• хэш или укороченный идентификатор данных,
• флаги валидации (например, validation_failed=true + список полей без содержимого),
• агрегаты (например, “ошибка схемы в поле birth_date”).

4) Контекст запроса: как добавлять поля, не превращая код в кашу

Когда вы добавляете correlation-id и другие поля, возникает типовая боль: “как не передавать всё вручную во все функции”.

Вариантов несколько:

1. Передавать контекст явно (через параметры) — просто, но часто неудобно.
2. Использовать context variables (contextvars) — идеально для асинхронщины.
3. Использовать middleware для HTTP/ASGI и hook’и для очередей — контекст наполняется централизованно.

На практике для Python-сервисов (особенно async) самый удобный и надёжный путь — contextvars.

4.1 Минимальный пример: contextvars и корреляционный логгер

Ниже — пример подхода, который можно адаптировать под ваш стек. Мы создадим контекст, который будет автоматически добавляться в каждую запись логов.

import contextvars
import logging
import json
import time
import uuid
from dataclasses import dataclass, asdict
from typing import Optional

# Контекст логирования
correlation_id_var = contextvars.ContextVar("correlation_id", default=None)
request_id_var = contextvars.ContextVar("request_id", default=None)
route_var = contextvars.ContextVar("route", default=None)

@dataclass
class LogContext:
    correlation_id: Optional[str] = None
    request_id: Optional[str] = None
    route: Optional[str] = None

def get_log_context() -> LogContext:
    return LogContext(
        correlation_id=correlation_id_var.get(),
        request_id=request_id_var.get(),
        route=route_var.get(),
    )

class JsonFormatter(logging.Formatter):
    def format(self, record: logging.LogRecord) -> str:
        base = {
            "ts": time.time(),
            "level": record.levelname,
            "logger": record.name,
            "message": record.getMessage(),
        }
        ctx = asdict(get_log_context())
        # Добавим только непустые значения
        base["context"] = {k: v for k, v in ctx.items() if v is not None}

        if record.exc_info:
            base["exc_info"] = self.formatException(record.exc_info)
        return json.dumps(base, ensure_ascii=False)

logger = logging.getLogger("app")
logger.setLevel(logging.INFO)

handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logger.addHandler(handler)
logger.propagate = False

Использование контекста в обработчике выглядит так:

from contextlib import contextmanager

@contextmanager
def log_context(correlation_id: str, request_id: str, route: str):
    token1 = correlation_id_var.set(correlation_id)
    token2 = request_id_var.set(request_id)
    token3 = route_var.set(route)
    try:
        yield
    finally:
        correlation_id_var.reset(token1)
        request_id_var.reset(token2)
        route_var.reset(token3)

def handle_request():
    corr_id = str(uuid.uuid4())
    req_id = "req-123"
    route = "/v1/orders"

    with log_context(correlation_id=corr_id, request_id=req_id, route=route):
        logger.info("request started")
        # ...
        logger.info("request finished", extra={"status_code": 200})

В этом примере extra лучше тоже формализовать (чтобы поля не “расползались”). Но даже базовая идея работает: контекст устанавливается один раз, а дальше логгер всегда “знает”, что добавлять.

Подводный камень: при использовании contextvars следите за тем, что контекст корректно переносится через задачи (asyncio.create_task). Обычно это работает, но при сложных паттернах важно тестировать.

5) correlation-id: как формировать и где хранить

Correlation-id нужен, чтобы связать:

• входящий запрос и все внутренние события,
• вызовы внешних сервисов,
• ретраи и деградации,
• последовательность сообщений (в зависимости от архитектуры).

5.1 Когда correlation-id особенно полезен

• сервис вызывает другие сервисы (HTTP/gRPC),
• есть очереди и асинхронная обработка,
• один запрос порождает цепочку событий (fan-out),
• инцидент расследуется “по следу”.

5.2 Кто должен генерировать correlation-id: клиент или сервер

Есть практическое правило:

• Если клиент прислал correlation-id (например, заголовком), сервер должен его принять и сохранить.
• Если клиент не прислал — сервер генерирует новый.
• Дальше сервер прокидывает correlation-id в исходящие запросы и сообщения.

Это обеспечивает трассируемость “вдоль цепочки”.

5.3 Формат correlation-id

Нет единого стандарта, но важны критерии:

• уникальность (UUIDv4/v7 или ULID),
• удобочитаемость,
• стабильность размера (не гигантская строка),
• безопасность (не включать секреты/PII).

Чаще всего используют UUID. Для продов иногда выбирают ULID/UUIDv7 (лучше для сортировки по времени), но UUIDv4 уже отлично подходит.

5.4 Пример: прокидывание correlation-id по HTTP (ASGI-ориентированный подход)

Если вы используете ASGI (FastAPI/Starlette) — идея похожа, в middleware можно:

• прочитать входящий заголовок,
• сгенерировать при необходимости,
• положить в contextvars,
• добавить заголовок в ответ.

Псевдокод ниже показывает принцип:

import uuid

CORR_HEADER = "X-Correlation-ID"

def get_or_create_correlation_id(incoming_headers: dict) -> str:
    val = incoming_headers.get(CORR_HEADER)
    if val:
        return val
    return str(uuid.uuid4())

А в обработке вы уже делаете:

• ставите correlation-id в контекст,
• логируете “вехи” запроса,
• используете то же значение при вызове внешнего API:

import requests

def call_downstream(url: str, payload: dict, correlation_id: str):
    headers = {
        "Content-Type": "application/json",
        "X-Correlation-ID": correlation_id,
    }
    resp = requests.post(url, json=payload, headers=headers, timeout=5)
    return resp

Подводный камень: корреляционный заголовок должен прокидываться во все точки выхода (HTTP, gRPC metadata, очередь), иначе цепочка будет рваться.

6) PII в логах: политика по умолчанию “safe by design”

PII — самая частая причина проблем с безопасностью и комплаенсом. В логах она возникает не потому что “кто-то злой”, а потому что:

• логируют “сырой” запрос целиком,
• логируют ошибки валидации, которые содержат пользовательский ввод,
• сохраняют stack trace, где могут быть пользовательские данные,
• используют repr(obj) для сложных структур.

6.1 Что значит “PII-safe” на практике

PII-safe стратегия включает:

1. Список категорий данных, которые нельзя логировать.
   • например: email/телефон/адрес/номер карты.
2. Маскирование: заменять часть данных на *** или хэш.
3. Редакция исключений: иногда полезно логировать тип ошибки и поле, а не полный текст.
4. Запрет payload’ов по умолчанию.
5. Тесты: хотя бы smoke-тест, что логирование не выведет PII.

6.2 Маскирование: пример функции для безопасного логирования

Допустим, у вас есть словарь с потенциально чувствительными полями. Введите простую редакцию:

from copy import deepcopy

SENSITIVE_KEYS = {"password", "token", "access_token", "refresh_token", "email", "phone", "card_number"}

def redact_pii(data: dict) -> dict:
    redacted = deepcopy(data)
    for k, v in redacted.items():
        key = k.lower()
        if key in SENSITIVE_KEYS:
            redacted[k] = "***REDACTED***"
        elif isinstance(v, dict):
            redacted[k] = redact_pii(v)
        elif isinstance(v, list):
            redacted[k] = [
                redact_pii(item) if isinstance(item, dict) else item
                for item in v
            ]
    return redacted

Дальше вы логируете отредактированную структуру, а не исходную:

payload = {"email": "user@example.com", "name": "Alice", "token": "abc"}
logger.info("request payload received", extra={"payload": redact_pii(payload)})

6.3 Stack trace и PII

Stack trace — это exc_info, иногда он содержит значения переменных из исключения. Проблема решается так:

• избегайте включать PII в текст исключения,
• при необходимости перехватывайте исключения и логируйте “обезличенный” вариант (error_type, error_code),
• если вы пишете stack trace — применяйте редакцию на уровне формируемого сообщения исключения.

7) Поля для алертов и трассировок: ориентир на “диагностические вопросы”

Логи для человека и логи для алертов — это разные интерфейсы. Для алертов важны поля, по которым можно быстро агрегировать и строить правила.

7.1 Что чаще всего нужно для алертов

Минимальный “алертный” набор для HTTP-сервисов:

• service, environment
• route или operation
• status_code (или outcome = success/failure)
• error_type
• duration_ms
• иногда upstream (внешний вызов) и его outcome
• correlation_id (не для алерта, а для расследования)

Пример: алерт “увеличение 5xx” лучше строить по route и status_code. А алерт “таймауты” — по upstream + error_type=TimeoutError.

7.2 Что полезно для трассировок (и как не дублировать OpenTelemetry)

Если вы используете distributed tracing (OpenTelemetry/Jaeger/Zipkin), correlation-id может дублироваться с trace_id. Но это не всегда плохо:

• trace_id — стандарт для трассировки,
• correlation_id — удобный “сквозной ключ” для логов и систем, которые не интегрированы с tracing.

Лучше сделать правило:

• если trace_id доступен — добавлять его,
• correlation-id поддерживать всегда (как fallback).

7.3 Одно событие — один JSON-сообщение

В проде вам обычно важнее, чтобы каждое лог-сообщение было структурой с предсказуемой схемой. Например:

• event="request_completed"
• duration_ms=...
• http_method="POST"
• route="/v1/orders"
• status_code=...
• correlation_id=...
• error_type=... (если была ошибка)

Тогда запросы к логам не превращаются в гадание по тексту.

8) Ошибки и исключения: как логировать, не теряя смысла

Есть две ошибки, которые встречаются постоянно:

1. Логировать исключение без контекста, в итоге stack trace “висит в воздухе”.
2. Логировать исключение дважды (и в middleware, и в обработчике).

8.1 Правильная схема: log на уровне “границы”

Обычно границы — это:

• middleware/endpoint (HTTP),
• consumer (очередь),
• job runner.

На границе вы делаете:

• correlation-id в контекст,
• одно логирование “итог запроса/сообщения”,
• stack trace при необходимости.

Внутри бизнес-слоя — меньше исключений наружу и больше “кейсных” событий (например, “не удалось получить данные из кеша, используем fallback” как WARNING).

8.2 Пример: логирование итогов запроса с duration и error_type

Идея: в try/except фиксируем результат и в одном месте пишем итог.

import time

def handle():
    start = time.perf_counter()
    try:
        # обработка
        status_code = 200
        logger.info("request completed",
                    extra={"event": "request_completed", "status_code": status_code})
    except Exception as exc:
        status_code = 500
        logger.error("request failed",
                     exc_info=True,
                     extra={
                         "event": "request_completed",
                         "status_code": status_code,
                         "error_type": type(exc).__name__,
                     })
        raise
    finally:
        duration_ms = (time.perf_counter() - start) * 1000
        # В идеале duration_ms добавлять во все итоговые события через форматтер/extra.
        logger.info("request duration",
                    extra={"event": "request_duration_ms", "duration_ms": duration_ms})

В реальности лучше сделать так, чтобы итоговое сообщение включало duration_ms, но пример иллюстрирует мысль: итог и контекст — в одном месте, а не размазаны по проекту.

Подводный камень: logger.error(..., exc_info=True) может стать дорогостоящим, если ошибки происходят часто. Тогда:

• регулируйте частоту (sampling),
• различайте ожидаемые ошибки и неожиданные,
• не логируйте stack trace для “валидационных” случаев.

9) Стратегия “levels × context × correlation-id” как система правил

Сведём всё в практичную матрицу.

9.1 Уровни

• INFO: итог обработки (request/message), важные бизнес-события.
• WARNING: деградации, ретраи, fallback’ы, необычные, но допустимые ситуации.
• ERROR: реальные сбои, приводящие к failure исходу операции.
• DEBUG: детальные внутренности для диагностики и только контролируемо.

9.2 Контекст

Минимальный единый контекст для всех событий:

• correlation_id
• request_id/message_id (если есть)
• route/operation
• environment/service

Дополнительно по необходимости:

• tenant_id, user_id (с проверкой на PII-политику)
• upstream и его статус/таймауты
• retry_count

9.3 Correlation-id

• принимаем входящий заголовок,
• генерируем при отсутствии,
• прокидываем во все исходящие запросы/сообщения,
• включаем в каждый ключевой лог шаг.

Эта тройка почти всегда приводит к тому, что логи становятся “смотримыми” в проде: вы можете взять correlation-id из одного запроса и быстро восстановить цепочку событий.

10) Инструментальная часть: структурированные логи и schema дисциплина

Чтобы логи были удобны, нужны два решения:

1. Структурированный формат (обычно JSON)
2. Дисциплина схемы: один event — набор полей, который почти не меняется

Минимально разумная практика:

• вводите поле event,
• различайте event="request_completed", event="upstream_call", event="message_failed",
• фиксируйте названия полей (например, duration_ms, status_code, error_type).

При таком подходе вы сможете писать алерты и отчёты не по тексту, а по полям.

Вывод: логирование как часть архитектуры наблюдаемости

Стратегию логирования в Python-сервисе нельзя свести к “добавим логгер и включим DEBUG”. В проде логирование — это архитектурная составляющая, которая определяет скорость диагностики, качество расследований и соблюдение требований безопасности.

Ключевые принципы, которые стоит внедрять системно:

• разграничить уровни (INFO/WARNING/ERROR) по смыслу, а не по привычке;
• логировать не всё, а релевантные вехи и поля, которые отвечают на диагностические вопросы;
• добавлять контекст запроса через единый механизм (например, contextvars) и избегать “ручной передачи” параметров;
• формировать correlation-id предсказуемо: принимать входящий заголовок, генерировать при отсутствии и прокидывать в исходящие запросы/сообщения;
• сделать PII-safe подход “по умолчанию”: редактировать чувствительные поля и не допускать утечки через payload’ы и stack trace;
• проектировать поля так, чтобы алерты и трассировки могли агрегировать события без парсинга текста.

Если хотите углубиться в практики построения observability (включая logging/tracing/метрики и корреляцию между ними), полезно посмотреть системный материал по теме: например, курс, который можно использовать как опорный маршрут для разбора концепций и практической реализации в Python — /course/.

Внедряя это по шагам (сначала единый контекст и correlation-id, затем схему событий, затем PII-редакцию), вы получите логи, которые не пугают инженеров в проде — и реально ускоряют работу при инцидентах.