dev-conventions/lang/go/logging.md

status, extends

status	extends
рекомендуемая	arch/time.md

Логирование

Как и когда писать логи. Это правила оформления кода (How), а не спецификация поведения: наблюдаемые требования к логам, входящие в контракт функциональности, живут в спеках.

Принципы

• Структурированный JSON (slog.JSONHandler), один формат для dev и prod. Не потому, что текстовый вывод «расходит поля» — смена хендлера структуру атрибутов не меняет; а потому, что с текстовым dev-выводом перестаёшь ежедневно гонять собственные jq-пайплайны, и поломки словаря замечаются только в проде.
• Сообщение (msg) — категория события; данные — в полях. Каждое поле — отдельный ключ с типизированным значением: это даёт фильтрацию и агрегацию через jq/DuckDB без регулярок.

{"time":"2026-06-28T11:23:45.123Z","level":"INFO","msg":"download accepted","download_id":"01jz2k7f8q9r3s4t5v6w7x8y9z","media_type":"movie"}

Время в записи

Поле time ставит slog, но UTC он по умолчанию не даёт: встроенные хендлеры пишут время в зоне самого time.Time, то есть в локальной зоне процесса. UTC ставится ReplaceAttr по slog.TimeKey — см. lang/go/time.md. Точность JSONHandler — миллисекунды, фиксированная ширина; это другая точность, чем в БД, и по arch/time.md так и должно быть: ширина фиксируется на носитель.

Сообщение

• msg — короткая константа в нижнем регистре: download accepted, recognition done, layout failed. Данные — в атрибутах: log.Info("download accepted", "download_id", id).
• msg — чистая категория без неймспейс-префикса: recognition done, а не recognize: done. Подсистема — отдельное поле, не текст.
• Смена состояния сущности — единая категория (state transition) с полями from/to/code. Какое именно состояние и по какой причине — это данные, а не текст. Тогда весь жизненный цикл собирается одним фильтром. Физический эффект сверх перехода — отдельная запись своей категории, она не подменяет запись перехода.

Уровни

Принцип: уровень — это адресат («кому сообщение»), а не «насколько громко сломалось».

Уровень	Кому и когда
DEBUG	разработчику при отладке; в проде выключен
INFO	владельцу, аудит постфактум
WARN	владельцу, «может стать проблемой»
ERROR	владельцу, в разбор

Правила:

• Уровень не зависит от подсистемы: ERROR везде одинаково серьёзен.
• WARN ≠ «ничего страшного». WARN = «может стать проблемой». Если это не «может» — это INFO.
• Меняется адресат — меняется уровень. Невалидный ввод от пользователя — DEBUG (норма, разбирать нечего), а не ERROR.
• Событийное → INFO, рутинно-частое → DEBUG. Операция по реальному действию или изменению — INFO. Повторяющаяся служебная операция, запускаемая таймером или поллингом и сама по себе не несущая события (healthcheck, опрос статуса, авто-рефреш UI), — DEBUG: на INFO она зашумляет аудит.
• slog не разделяет CRITICAL/FATAL — фатальный сбой на старте логируем ERROR и завершаем процесс с ненулевым кодом.

Поля: единый словарь

Главное условие — одно поле, одно имя по всему коду (не mediaType/media/media_type вперемешку).

• Бизнес-поля — плоский snake_case.
• Системные домены — точечная иерархия (адаптация OpenTelemetry): http.*, ext.*.
• JSON плоский: все поля на верхнем уровне, без вложенности.

Когда добавляем	Поля
входящий HTTP-запрос (middleware)	http.method, http.route, http.status_code, duration_ms, transport — если транспортов больше одного
работа с сущностью (scoped-логгер)	<entity>_id и доменные атрибуты
запись об ошибке	error
вызов внешнего сервиса	ext.service, ext.operation, ext.status_code, duration_ms, retry

service.* и host.* не заводим — для одного бинаря на одном хосте это шум. Если появятся несколько инстансов, добавим service.version одной строкой при старте.

Корреляция по id сущности

Отдельный случайный trace_id не заводим, если у сущностей есть стабильные уникальные идентификаторы — они и служат ключом корреляции. (Как их выбирают — arch/db-identifiers.md, если конвенция взята.)

• Каждая запись, относящаяся к сущности, несёт её id в поле <entity>_id. Для долгой операции — scoped-логгер, протаскиваемый через context.Context сквозь асинхронные стадии, чтобы ключ дописывался сам:

log := log.With("download_id", id)
ctx = logctx.With(ctx, log) // достаём логгер из ctx в каждой стадии

• Все записи одной операции собираются одним фильтром: jq 'select(.download_id=="01jz…")' app.jsonl.
• Если id глобально уникален across сущностей, штатно работает и простой grep по голому id — он находит все упоминания независимо от имени поля.

Ошибки

Go-ошибки логируем атрибутом, не текстом сообщения: log.Error("layout failed", "error", err, "download_id", id). Ключ — error (как по умолчанию в zap/zerolog: единый ключ важнее краткости).

• Идиома Go — либо лог, либо возврат, не оба. Промежуточные слои только оборачивают и возвращают (%w), не логируя: контекст накапливается в цепочке.
• Логируем ошибку один раз — на границе доменного слоя, которая определяет исход операции. Логирует этот единый чокпоинт, а не каждый транспорт: так транспорты остаются тонкими, и один сбой не даёт дублей.

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

• Уровень доменного отказа — по адресату, а не по месту. У каждой доменной ошибки ровно один логирующий; уровень выбирает он:

  Класс отказа	Кому	Уровень
  штатный конфликт состояния или некорректный ввод	пользователю, он уже получил ответ	DEBUG
  расхождение производного или учётного состояния, первичные данные целы	владельцу, «может стать проблемой»	WARN
  сбой БД, ФС, недоступность зависимости	владельцу, в разбор	ERROR

• Тот же класс отказа в асинхронной стадии (пользователь не ждёт) адресован уже владельцу как деградация автоматики — уровень поднимается. Коллизия в ручном действии — DEBUG (человек видит причину на экране), в авто-обработке — WARN (автоматика не довела задачу).

• Повторяющийся сбой фонового цикла — WARN, не ERROR. Одиночный промах тика транзиентен: следующий тик повторит. Тот же класс сбоя внутри синхронной операции — ERROR, потому что операция провалилась целиком и повтора нет. Уровень задаёт не текст ошибки, а наличие штатного повтора.

Два цикла повтора — не путать

Слово «ретрай» означает два разных механизма, и уровень считается по каждому отдельно:

• Повтор вызова внутри одной операции (ретраи HTTP-клиента) — по нему выбирается уровень ext-записи: WARN на попытку, ERROR когда попытки исчерпаны.
• Повтор тика внешним циклом (поллинг, сверка) — по нему выбирается уровень доменной записи об исходе тика: WARN, потому что следующий тик повторит.

Из этого следует, что у лежащей зависимости ext-запись пишет ERROR каждый тик. Это и есть механизм эскалации: доменный слой не паникует, а телеметрия зависимости честно показывает, что она недоступна. Если поток ERROR от поллинга мешает — это лечится понижением частоты тика или подавлением повторов в самом клиенте, а не переклассификацией уровня.

Внешние сервисы: логируем все вызовы

Каждый вызов внешнего сервиса логируется — это единственный способ отличить «у нас баг» от «зависимость легла». Поля: ext.service, ext.operation (логическая операция, не URL), ext.status_code, duration_ms, retry.

Уровни:

• INFO — успешный событийный вызов;
• DEBUG — успешный рутинно-частый вызов (поллинг, авто-рефреш);
• WARN — попытка не удалась, делаем retry;
• ERROR — ретраи исчерпаны, сервис недоступен.

Завершённый HTTP-ответ с 4xx — это успех на транспортном уровне (ext.status_code записан); решение «это ошибка» принимает доменный вызывающий. Тело запроса и ответа — только на DEBUG и после вычистки секретов.

HTTP и healthcheck

• Входящие запросы логируем с http.* и duration_ms на INFO: это аудит обращений, а не отладка. Уровень не понижается из-за кода ответа — 4xx остаётся INFO-записью доступа; решение «это ошибка» принимает доменный слой и пишет свою запись.
• Для корреляции запроса допустим request_id — это отдельный слой от корреляции по сущности и не противоречит отказу от trace_id.
• Healthcheck, liveness, readiness — DEBUG. Их дёргают периодически, на INFO они забивают аудит; в проде с базовым INFO они не пишутся.

Безопасность: что не логируем

Никаких секретов в полях и сообщениях: пароли и cookie сессий, API-ключи и токены, Authorization-заголовки, аутентификационные параметры в ссылках.

• Тела ответов внешних API и сырой вывод LLM (недоверенный, может быть большим) — только на DEBUG, с вычисткой и обрезкой по длине.
• При сомнении — не логируем значение, логируем факт его наличия ("has_api_key", true).
• Ошибка HTTP-транспорта несёт URL — потенциальный носитель секрета. *url.Error встраивает полный URL запроса, а секрет может жить прямо в нём: токен в пути, api_key в query. Go редактирует только пароль из userinfo, остального не трогает. Санитизируем на границе клиента до лога и обёртки: разворачиваем *url.Error в первопричину. Цена — теряется Op и сам факт «это был HTTP-транспорт» (errors.Is на причину сохраняется); альтернатива с редактированием URL сохранила бы структуру, но сложнее. Порядок важен: санитизация идёт раньше трансляции ошибки в доменную (lang/go/errors.md), иначе секрет уедет в обёртку.
• Общее правило: секрет не кладём в URL, если у API есть заголовок — тогда его нет и в ошибке транспорта.

Куда пишем

• JSON в stdout одним потоком; сбор и ротацию делает окружение (docker, journald). По файлам не маршрутизируем.
• Базовый уровень в проде — INFO, DEBUG включается конфигом. dev — DEBUG.

Анализ

• Повседневно — jq: jq 'select(.download_id=="a1b2")' app.jsonl.
• Тяжёлое (агрегации, JOIN) — DuckDB поверх JSONL прямо из файла.