Логи

Лог — это письмо самому себе в будущее, которое будет прочитано в самый неудобный момент: во время инцидента, в спешке, человеком, который не писал этот код. Эта глава о том, как писать такие письма, чтобы их можно было прочитать.

Зачем нужны логи

У логов три законных применения: расследование инцидентов, аудит (кто и когда выполнил действие) и отладка во время разработки. Для подсчёта событий и построения графиков логи подходят плохо — для этого есть метрики, которые дешевле хранить и быстрее агрегировать. Если строка лога пишется только для того, чтобы потом посчитать количество таких строк, её стоит заменить счётчиком.

Это различие определяет, что попадает в лог. Для расследования нужен контекст конкретного события: какой запрос, какой пользователь, какие входные данные, что пошло не так. Для метрик нужен только факт события и несколько измерений. Смешивание этих задач приводит к логам, в которых много строк и мало информации.

Уровни логирования

Уровень — основной инструмент фильтрации. Большинство библиотек поддерживают похожий набор: DEBUG, INFO, WARNING, ERROR, CRITICAL. Стандарт syslog (RFC 5424) определяет восемь уровней, но на практике тонкие различия между ними мало кто соблюдает. Важнее договориться о смысле каждого уровня внутри команды и соблюдать договорённость.

ERROR — операция не выполнена, и это требует внимания человека. Если после записи с уровнем ERROR никто ничего не должен делать, уровень выбран неверно.
WARNING — операция выполнена, но в необычных условиях: сработал повторный запрос, использовано значение по умолчанию, ответ пришёл медленнее ожидаемого. Одиночное предупреждение не требует реакции, рост их числа — требует.
INFO — значимые события жизненного цикла: запуск и остановка сервиса, применение конфигурации, завершение фоновой задачи. Не каждый обработанный запрос.
DEBUG — подробности для разработчика. В рабочем окружении по умолчанию выключен.

Подробная таблица с критериями и примерами сообщений — в разделе «Уровни логирования».

Самая распространённая ошибка — запись ожидаемых ситуаций с уровнем ERROR. Пользователь ввёл неверный пароль — это не ошибка сервиса, это нормальная работа. Внешний API вернул 404 на запрос несуществующего объекта — тоже. Если такие события пишутся как ошибки, фильтр по уровню ERROR перестаёт работать, и настоящие ошибки тонут.

Структурированное логирование

Строка вида User 4821 failed to pay order 99312: card declined удобна для чтения глазами, но неудобна для поиска. Чтобы найти все отказы по картам для конкретного заказа, придётся писать регулярное выражение, которое сломается при первом изменении формулировки. Структурированный лог записывает то же событие как набор полей:

json

{"ts": "2026-04-14T09:31:52.418Z", "level": "WARNING", "logger": "payments.charge",
 "msg": "payment declined", "order_id": 99312, "user_id": 4821,
 "reason": "card_declined", "provider": "acquirer-a", "attempt": 1,
 "trace_id": "4bf92f3577b34da6a3ce929d0e0e4736", "duration_ms": 842}

Сообщение msg остаётся коротким и постоянным, а все переменные части вынесены в поля. Теперь поиск по reason="card_declined" работает независимо от текста, а поле trace_id связывает запись со всеми остальными событиями того же запроса, в том числе в других сервисах.

Обязательные поля

Минимальный набор, который стоит зафиксировать для всех сервисов: время в UTC с миллисекундами, уровень, имя логгера или модуля, короткое сообщение, идентификатор трассировки или запроса. Имена полей лучше согласовать между сервисами заранее — например, взяв за основу семантические соглашения OpenTelemetry. Иначе в одном сервисе будет user_id, в другом userId, в третьем uid, и сквозной поиск станет невозможен.

Пример на Python

Стандартный модуль logging позволяет получить JSON-логи без сторонних библиотек. Дополнительные поля передаются через параметр extra:

python

import json
import logging
import time

RESERVED = set(vars(logging.makeLogRecord({}))) | {"message", "asctime"}

class JsonFormatter(logging.Formatter):
    converter = time.gmtime

    def format(self, record):
        doc = {
            "ts": self.formatTime(record, "%Y-%m-%dT%H:%M:%S") + f".{int(record.msecs):03d}Z",
            "level": record.levelname,
            "logger": record.name,
            "msg": record.getMessage(),
        }
        for key, value in vars(record).items():
            if key not in RESERVED:
                doc[key] = value
        if record.exc_info:
            doc["exc"] = self.formatException(record.exc_info)
        return json.dumps(doc, ensure_ascii=False, default=str)

handler = logging.StreamHandler()
handler.setFormatter(JsonFormatter())
logging.basicConfig(level=logging.INFO, handlers=[handler])

log = logging.getLogger("payments.charge")
log.warning("payment declined", extra={"order_id": 99312, "reason": "card_declined"})

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

Семплинг и подавление повторов

Когда что-то ломается, одна и та же ошибка часто повторяется тысячи раз в секунду: каждый запрос к недоступной базе данных пишет одинаковую строку. Такой поток не добавляет информации, но может перегрузить систему сбора логов и вытеснить из буфера действительно полезные записи.

Решение — ограничивать частоту одинаковых сообщений. Простейший вариант: пропускать первые N повторов в заданном окне, а остальные отбрасывать до начала следующего окна. Фильтр подключается к обработчику через handler.addFilter(RateLimitFilter()).

python

import logging
import time

class RateLimitFilter(logging.Filter):
    def __init__(self, per_window=10, window=60.0):
        super().__init__()
        self.per_window = per_window
        self.window = window
        self.seen = {}

    def filter(self, record):
        key = (record.name, record.levelno, record.msg)
        now = time.monotonic()
        start, count = self.seen.get(key, (now, 0))
        if now - start > self.window:
            start, count = now, 0
        self.seen[key] = (start, count + 1)
        return count < self.per_window

Ключ строится по шаблону сообщения (record.msg), а не по готовому тексту, поэтому строки, различающиеся только значениями параметров, считаются одинаковыми. Полезное дополнение — в начале нового окна записывать, сколько сообщений было отброшено в предыдущем, чтобы масштаб проблемы оставался виден.Семплинг имеет смысл применять к уровням INFO и WARNING; ошибки, как правило, лучше записывать все, а ограничивать их объём на стороне системы сбора.

Не семплируйте аудит

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

Ротация и срок хранения

Если сервис пишет в файлы, ротация обязательна: без неё диск рано или поздно заполнится, и сервис остановится по причине, не имеющей отношения к его работе. На Linux для этого обычно используют logrotate:

text

/var/log/billing/*.log {
    daily
    rotate 14
    maxsize 500M
    compress
    delaycompress
    missingok
    notifempty
    copytruncate
}

Параметр copytruncate нужен, если приложение не умеет переоткрывать файл по сигналу; он может потерять несколько строк в момент ротации, поэтому для сервисов, которые умеют обрабатывать сигнал, лучше использовать postrotate с отправкой сигнала процессу.

Срок хранения выбирается исходя из того, как далеко в прошлое приходится заглядывать при расследовании. Для большинства сервисов двух-четырёх недель подробных логов достаточно; аудит хранится столько, сколько требует регламент. Хранить всё вечно «на всякий случай» дорого и не даёт пользы: логи годичной давности почти никогда не читают.

Типичные ошибки

Персональные данные в логах. Пароли, токены, номера карт и полные тела запросов не должны попадать в лог. Маскирование нужно встраивать в форматтер, а не надеяться на аккуратность каждого разработчика.
Лог вместо исключения. Запись ошибки в лог и продолжение работы как ни в чём не бывало скрывает проблему. Если операция не удалась, вызывающий код должен об этом узнать.
Двойное логирование. Исключение записывается на каждом уровне стека, через который проходит. В итоге одна ошибка даёт пять записей. Логировать стоит там, где ошибка обрабатывается, а не там, где она пробрасывается дальше.
Отладочный вывод в рабочем окружении. Уровень DEBUG, включённый для расследования, остаётся включённым месяцами. Удобно иметь возможность менять уровень без перезапуска, но с автоматическим возвратом через заданное время.

Итог

Логи — для расследования и аудита, метрики — для подсчёта. Не пишите строку лога, которую будут только считать.
ERROR означает «нужно действие человека». Ожидаемые ситуации записываются с более низким уровнем.
Структурированные логи с согласованными именами полей и идентификатором трассировки превращают поиск из угадывания в запрос.
Повторяющиеся сообщения ограничиваются по частоте; аудит не семплируется никогда.
Ротация и срок хранения задаются явно для каждого потока логов.