Логи пишут все. Читают их тогда, когда уже плохо, — и вот тут выясняется, что написаны они были для того, кто их писал, а не для того, кто их читает через полгода в четыре часа ночи.
Разница между текстовым журналом и структурированным становится видна не в теории, а на конкретном расследовании. Возьмём одно настоящее.
#Инцидент
Обновление кода прошло, скрипт деплоя доложил об успехе, сайт открывается. Через час становится понятно, что сайт отдаёт код прошлой версии. Нужно понять, что произошло: маркер запроса на перезапуск не дошёл, дошёл и был отвергнут, или был принят, а перезапуск не удался.
#Как это выглядит в текстовом журнале
2026-08-25 04:12:03 INFO watchdog probe ok
2026-08-25 04:13:03 INFO watchdog probe ok
2026-08-25 04:13:04 INFO restart request found
2026-08-25 04:13:04 WARNING ignored
2026-08-25 04:14:03 INFO watchdog probe ok
Что здесь есть: факт, что запрос нашли и проигнорировали. Чего здесь нет: почему. Причин у отказа шесть — маркер протух, чужой репозиторий, повтор nonce, не тот владелец файла, слишком короткий интервал между запросами, битое содержимое. Строка ignored не различает ни одну из них.
Дальше начинается то, на что уходит вечер: grep по журналу, попытка сопоставить время с историей команд, чтение исходников, чтобы понять, при каких условиях печатается именно это слово. И всё это ради одного бита информации, который приложение знало в момент события и не записало.
#Как это выглядит в структурированном журнале
{"ts":"2026-08-25T04:13:04Z","level":"warning","event":"restart_request.ignored",
"reason":"stale","age_s":412,"max_age_s":300,"nonce":"9f2c…","repo":"C:\\www\\Persona",
"requested_version":"2.34.0","serving_version":"2.33.1","pid":21098}
Расследование заканчивается на первой строке: маркер протух — между его записью и первым тиком watchdog прошло 412 секунд при потолке в 300. Значит деплой падал не на правах и не на валидации, а на времени: watchdog не тикал больше семи минут. Следующий вопрос — почему не тикал — задаётся уже к планировщику, а не к приложению.
Смысл структурированных логов ровно в этом. Не в JSON как формате, а в том, что событие несёт своё состояние: не «отказано», а «отказано, потому что 412 больше 300».
#Минимальный набор обязательных полей
Дальше начинается вкусовщина, и чтобы её ограничить, полезно зафиксировать минимум. Пять полей, без которых событие бесполезно, и три, которые окупаются на второй же неделе.
| Поле | Обязательно | Зачем |
|---|---|---|
ts |
да | время в UTC и в ISO-формате, не в локальном |
level |
да | отделить рабочий шум от происшествия |
event |
да | стабильный машинный идентификатор, не фраза |
logger |
да | какой модуль, чтобы сузить область |
reason |
да при отказе | различить причины одного и того же отказа |
request_id |
желательно | сшить строки одного запроса |
user_id |
желательно | сшить строки одного пользователя |
duration_ms |
желательно | увидеть деградацию до того, как пожалуются |
Главное поле — event. Оно должно быть машинным идентификатором с точкой, а не человеческой фразой: restart_request.ignored, а не Restart request was ignored. Фразу перепишут при следующей правке текста, и все ваши фильтры перестанут находить события. Идентификатор переживает и правку текста, и перевод интерфейса.
Правило, которое из этого следует: человеческий текст в логах не нужен вообще. Человеческую формулировку соберёт тот, кто читает; событию нужны идентификатор и поля.
#Чего в логах быть не должно
Здесь у нас есть собственный шрам, и он дороже, чем кажется.
В коде были строки вида logger.error("share_corrupt", token=token) — то есть токен доступа по ссылке уезжал в файл журнала открытым текстом. Журналы попадают в диагностические архивы, прикладываются к обращениям в поддержку, лежат на диске без шифрования. Токен, попавший в лог, надо считать выданным наружу.
Исправление было не только в том, чтобы убрать эти строки, а в том, чтобы такие строки перестали появляться. И вот тут выяснилась деталь, ради которой стоит писать этот раздел: регулярное выражение эту задачу не решает. По тексту логов одинаково хорошо совпадают reason="missing_token", token_id=… и max_tokens=… — ни одно из них не утечка. Проверка, которая шумит на девяноста процентах совпадений, отключается через неделю и после этого не защищает ничего.
Рабочий вариант — разбирать исходный код как дерево и срабатывать только тогда, когда аргумент и есть секрет: голое имя или атрибут, названные token, secret, password, api_key. На нашей кодовой базе такая проверка дала два попадания и ноль ложных срабатываний. Ещё одна деталь, которая оказалась несущей: первая версия проверки искала только логгеры с именами log и logger и молча пропустила две настоящие утечки, спрятанные за локальным именем. Проверять надо любую переменную, которая ведёт себя как логгер.
Как эта проверка ставится в git-хук и что ещё она должна ловить — в статье про секреты в проекте и защиту от коммита.
Отдельно про заимствованные утечки: если такие строки уже есть в чужом коде и чинить их не вам, заведите список исключений с причиной на каждую запись — но обязательно с проверкой, что исключение протухает, когда утечка исправлена. Иначе устаревшая запись будет вечно глушить свой ключ, а именно так первая версия нашего списка и спрятала две живые утечки.
#Куда писать
Правило простое и почти всегда правильное: приложение пишет в стандартный вывод, ротацией занимается система. Собственный файловый обработчик с ротацией внутри приложения — источник двух отдельных проблем: он теряет строки при жёсткой остановке и он же ломается при запуске нескольких процессов, которые пишут в один файл.
На Linux стандартный вывод подхватит журнал системы; на Windows задача расписания пишет вывод туда, куда вы её направите. Как это настраивается вместе с корректной остановкой воркеров — в гайде про автозапуск сервиса через systemd.
Отдельная строка в регламенте: логи фоновых операций, которые идут пачками — миграции, переиндексация, обработка очереди, — должны нести число обработанных элементов и длительность. Без них вопрос «миграция зависла или просто долгая» не имеет ответа; про сам порядок безопасного применения схемы — в статье про миграции базы данных без потери данных.
#Проверка результата
Формальная проверка одна, и она делается не грепом, а сценарием.
- Возьмите самый неприятный отказ, который у вас случался.
- Воспроизведите его на стенде.
- Найдите в логах одну строку, из которой понятно, что произошло и почему.
Если такой строки нет — набор полей неполный. Если строк нужно три и они в разных местах — не хватает сквозного идентификатора запроса. Если строка есть, но в ней человеческая фраза без чисел — событие не несёт своего состояния.
Второй критерий, более жёсткий: попробуйте посчитать по логам, сколько раз за неделю случался этот отказ. Со структурированными логами это одна команда фильтрации по event. С текстовыми — это неразрешимая задача, потому что формулировка менялась трижды.
#Что может пойти не так
JSON сделали, полей не добавили. Формат сам по себе ничего не даёт. {"msg":"error occurred"} ничем не лучше текстовой строки, только читается хуже.
Логов стало слишком много. Структурированность провоцирует писать всё подряд. Ориентир: событие уровня info пишется на смену состояния, а не на каждый шаг. Всё остальное — debug, выключенный по умолчанию.
Время в локальной зоне. При расследовании инцидента, случившегося при переводе часов или на машине в другой зоне, локальное время превращает хронологию в загадку. Только UTC, только ISO.
Секрет уехал в поле. См. раздел выше. Проверять надо автоматически, потому что вручную это не ловится.
Логи есть, но их никто не читает. Логи — это инструмент расследования, а не оповещения. Узнавать о сбое надо из проверок, а не из журнала; какие именно проверки нужны — в статье про мониторинг личного сервиса.
#Частые вопросы
#Обязательно ли использовать JSON?
Нет. Обязательно, чтобы событие несло поля, а не фразу. Формат «ключ=значение» читается человеком лучше и фильтруется почти так же хорошо. JSON выигрывает, когда логи уезжают в систему хранения с индексом.
#Что делать с логами сторонних библиотек?
Пропускать через тот же обработчик, чтобы формат был один. Иначе половина журнала окажется в чужом формате и ваши фильтры будут её терять — а именно в этой половине обычно и лежит причина отказа.
#Как долго хранить логи?
От двух недель до месяца для рабочих логов личного сервиса. Дольше хранят агрегаты, а не строки. Помните, что логи содержат тела запросов и потому требуют такого же обращения, как данные пользователей.
#Что писать в лог у агента, который ходит по инструментам?
Там нужен не просто лог, а трассировка: вызов инструмента, его аргументы, результат и решение модели. Это отдельная задача — она разобрана в статье про отладку агента через логи и трассировку.
#Нужен ли сквозной идентификатор запроса на личном сервисе?
Да, и он окупается быстрее всего. На однопользовательском сервисе строки одного запроса ещё можно сопоставить по времени; как только пользователей стало двое, а фоновых воркеров пять, без идентификатора хронология превращается в кашу.
#Стоит ли логировать успешные операции?
Успешные — на уровне смены состояния: запуск, остановка, применённая миграция, завершённая пачка. Каждый успешный HTTP-запрос логировать не нужно, для этого есть счётчики. Разбор общего маршрута эксплуатации, где логи — одна из частей, — в статье о том, как поднять свой ИИ-сервис.