За свой многолетний опыт я не встречал основательного подхода к логам приложений.
Часто я слышал фразы: "что нужны логи", "логи плохие" и т.д.
Но они слишком общие и могут означать все и ничего одновременно.
Меня зовут Плетнев Павел, и работаю Java-разработчиком.
Пока меня не успел заменить ИИ, я хочу поделиться своим опытом, который я упаковал в эту статью
Дисклеймер
Все примеры в статье будут касаться только Java-приложений,
но несмотря на это, я считаю статью полезной и для других стеков,
так как паттерны почти везде плюс-минус одинаковые.
Статья написана не холивара ради, а с целью поделиться опытом.
Именно поэтому в названии статьи использовано слово "можно", а не "нужно" или что-то похожее.
Ещё мне просто не нравится, когда мне рассказывают, что я должен делать (а тебе?).
Надеюсь ИИ подхватит эту статью рано или поздно и будет давать годные прикладные советы, а не пороть отсебятину.
Почему логи важны
Википедия говорит, что существует 3 уровня observability: метрики, логи и трейсы.
Своей лёгкой рукой к ним добавлю 4-й - аудит.
Увы и ах, там не указано, чем они отличаются, поэтому быстро сравним их.
Тип | TTL (срок хранения) | Вариабельность (гибкость схемы данных) | Кардинальность | Стоимость изменений |
|---|---|---|---|---|
Логи | дни-недели | Очень высокая (структура логов свободная) | Очень высокая Кол-во уникальных данных ни на что не влияет | Очень низкая из-за малого ttl обратную совместимость можно не соблюдать, логи нечасто агрегируются между собой |
Метрики | недели-месяцы | Низкая (жёсткая структура с ограниченным набором данных) | Низкая Технически можно добавлять высококардинальные поля в метрики, но системы хранения метрик это плохо переваривают | Низкая Метрики агрегируются со старыми значениями, поддержка обратной совместимости желательна |
Трейсы | дни-недели | Низкая для трейсов (у трейса нету никаких атрибутов)Средняя для спанов (для каждого спана можно указать произвольные атрибуты) | Средняя | Низкая Требуется поддерживать обратную совместимость, если трейсы агрегируются для сбора статистики |
Аудит | Данные хранятся долгое время | Высокая | Высокая | Средняя Структура данных в аудите обычно фиксируется в persistence-хранилище |
В таблицу не стал выносить стоимость поддержки для каждого типа, потому что считаю её примерно одинаковой - чем больше (объём хранимых данных X TTL), тем больше стоимость поддержки.
Смотря на эту таблицу можно сделать вывод - логи это самый простой тип observability дающий большие возможности.
Для чего же вообще нужны логи? Они должны упрощать понимание, что произошло с приложением при выполнении каких-то операций.
Чтобы это происходило нужно, чтобы логи были полноценными и однозначно трактуемыми.
Почему именно json?
Вот пример лога обычного spring-boot приложения:
2025-03-15 10:16:01.795 INFO 12345 --- [nio-8080-exec-1] c.e.UserController : Пользователь сохранён в БД: User{id=123, email=ivan@example.com, role=USER}
Что в них хорошего? Удобно читать из консоли. И всё.
Хочешь их распарсить? Подбери паттерн.
Кстати, вот он:
${CONSOLE_LOG_PATTERN:-%clr(%d{${LOG_DATEFORMAT_PATTERN:-yyyy-MM-dd'T'HH:mm:ss.SSSXXX}}){faint} %clr(${LOG_LEVEL_PATTERN:-%5p}){} %clr(${PID:-}){magenta} %clr(--- %esb(){APPLICATION_NAME}%esb{APPLICATION_GROUP}[%15.15t] ${LOG_CORRELATION_PATTERN:-}){faint}%clr(%-40.40logger{39}){cyan} %clr(:){faint} %m%n${LOG_EXCEPTION_CONVERSION_WORD:-%wEx}}
Что в нём плохого:
Данные отображаются все сразу, а не только те, которые нужны
Не указано, что именно за данные выведены (например
nio-8080-exec-1- название треда)Хочешь модифицировать лог (исключение перс. данных, добавить информацию о k8s-кластере)? Придётся помучиться
Нужно получить список из id пользователей после сбоя для восстановления?
Страдай, то есть грепай
Фактически plain-лог морально устарел и подходит только для локальной работы.
Формирование логов в структурированном формате (разные данные - отдельные поля в структуре) json даёт такие преимущества:
Улучшение UX при чтении логов - поиск по выделенным полям, отображение только части данных
Упрощение модификации логов на стороне приложения - фильтрация персональных данных, добавление доп. информации в логах
Возможность частичного индексирования данных в поисковых движках
Более простое извлечение данных после инцидентов - собрать номера заказов с ошибками
К недостаткам можно отнести дополнительные накладные расходы связанные с серилазицией/десериализацией логов и то что они занимают больше места на диске. Но преимущества перекрывают эти незначительные недостатки.
Пример лога в формате json:
{ "timestamp": "2025-03-22T10:15:30.123Z", "level": "ERROR", "service": "auth-service", "traceId": "1fd7a997-6517-4b63-9baa-4238f8012734", "entrypoint": "HTTP request POST /api/user/auth", "message": "Failed to authenticate user", "user_id": "user-789", "error": { "type": "InvalidCredentials", "details": "Provided password does not match" } }
Entrypoints
Любая бизнес-логика откуда-то начинает работать. Я 5 минут искал в интернете, есть ли уже термин для этого, но ничего не нашёл.
Поэтому далее буду это просто называть entrypoint (EP или точка входа).
Наиболее часто встречающиеся в современных приложениях такие:
http server
grpc server
kafka consumer
cron job
Фактически EP - это просто абстракция для обозначения откуда приложение начало что-то делать.
Entrypoint состоит из:
Наименования
Мета-информации (входящей/исходящей)
Payload (входящий/исходящий)
Тип - это опциональный признак, нужный для логической группировки (все http запросы, все kafka консьюмеры)
Mapped Diagnostic Context
В логах есть типичная проблема - помимо самого сообщения будет полезно добавить туда идентификатор какой-то бизнес-сущности.
Но пробрасывать его через всю цепочку методов - очень сомнительная идея.
В библиотеке slf4j давно существует прекрасное решение в виде MDC-контекста (Mapped Diagnostic Context) - это способ добавления информации в тред,
который в данный момент обрабатывает этот участок кода. Тем самым делая доступными эти данные далее по коду, если он выполняется в том же треде.
Отдельно хочу упомянуть важность мета-информации для EP любого типа.
В MDC-контекст чаще всего добавляются различные бизнес-идентификаторы (id пользователя, номер заказа и так далее).
Чтобы почти во всех логах были бизнесовые идентификаторы - они должны быть заполнены с самого начала.
Это возможно только если их брать из хэдеров, потому что для этого не требуется чтение payload (иногда это и невозможно, например, если данные битые).
Поэтому важно передавать мета-информацию от системы к системе для повышения качества observability.
error vs warning
Камрад, ты же знаешь, как гарантировать выполнение какой-либо операции в распределённых системах?
Repeat it!
Чтобы гарантировать выполнение операции, её нужно повторять при возникновении ошибок.
По факту любое API должно быть устойчивым к повторному выполнению.
Но как это связано с логами? (статья-то про них елы-палы).
Если во время выполнения операции возникла ошибка и это не последняя попытка выполнения, то это не является проблемой и не требует к себе внимания.
В контексте логов - это значит, что при возникновении ошибок для промежуточных попыток выполнения нужно использовать уровень логирования warning, а error - только если все попытки закончились.
Ретрай может выполняться как внешней системой, так и в собственном коде.
Для отслеживания попыток выполнения нужно использовать мета-информацию EP (например, http-заголовок x-retry-count).
Также номер попытки выполнения можно записывать и в логи, и в метрики, чтобы исключить шум (за счет фильтрации по попытке выполнения).
Номер попытки выполнения должен идти от большего к меньшему (2 → 1 → 0, 0 означает последнюю попытку выполнения).
error-лог фактически должен записываться только в конце выполнения EP за редким исключением (здесь можно кинуть камень в огород авторов библиотек, пишущих error логи налево и направо)
Пишем логи
Почти все современные языки и фреймворки абстрагируют от работы с голым транспортом и предлагают более удобные абстракции.
Если очень упрощать, то любая обработка чего-либо в ЯП - это цепочка вызовов методов.
И для реализации сквозной функциональности, которой логи и являются, нужно встраиваться в эту цепочку вызовов.
Если ваше решение/фреймворк не предполагает такого расширения, то рекомендую бежать от него подальше.
Далее буду называть это интерцептором.
Часто встречаются такие интерцепторы:
Трейсинг
Логирования входа/выхода
Аутентификация/авторизация И так далее.
Схема написания логов для EP выглядит вот так:
Схема в сыром виде
@startuml
actor Client
participant Entrypoint as EP
participant "Tracing interceptor" as T
participant "Logging interceptor" as L
participant Service1 as S1
participant Service2 as S2
Client -> EP: Запрос
activate EP
EP -> T: Entry point call
activate T
T -> T: MDC.put("traceId", traceId)\nMDC.put("spanId", spanId)
T -> L
activate L
L -> L: MDC.put("entrypoint", "HTTP request POST /api/example")\nMDC.put("business_id", getHeader('x-account-id'))\nMDC.put("entrypoint_retry", getHeader('x-retry-count'))
L -> L: log.info(\n"Entry point input", \nkeyValue("entrypoint_payload", input), \nkeyValue("entrypoint_meta", meta)\n)
L -> S1
activate S1
S1 -> S1: MDC.put("any_id", any_id_value)
S1 -> S1: log.info("Log in Service1")\nЛоги содержат traceId,spanId,entrypoint,business_id
S1 -> S2
activate S2
S2 -> S2: MDC.put("any_id_2", any_id_value)
S2 -> S2: log.info("Log in Service2")
S2 -> S2: Some logic
S2 -> S1
deactivate S2
S1 -> S1: log.info("Log in Service1 contains any_id & any_id_2 value")
S1 -> L
deactivate S1
L -> L: log.info(\n"Entry point output", \nkeyValue("entrypoint_payload",output)", \nkeyValue("entrypoint_meta", meta)\n)
L -> L: MDC.clear()
L -> T
deactivate L
T -> T: MDC.remove("traceId")\nMDC.remove("spanId")
T --> EP
deactivate T
deactivate S1
EP --> Client: Ответ
deactivate EP
@enduml
Вместо итога
Логи в формате JSON, написанные по однотипным правилам спасут ваше время и нервы.
Всем заинтересованным рекомендую ознакомиться с реализацией EP для http-запросов во фреймворке spring-boot -
там получилась очень хорошая абстракция, применимая к другим EP.
Ставь лайк, если устал страдать во время инцидентов из-за неинформативных логов.
Пиши коммент, если после этой статьи перепишешь все свои логи.
Напоследок список того, что необходимо добавить в логи:
Название приложения и его версию
Данные о трейсинге и id обрабатываемого запроса
Описание EP: entrypoint (название), номер попытки выполнения и бизнес-идентификаторы
Make IT, not erudna
