# Логирование

Конвенция: *как* и *когда* писать логи в jellybit. Это правила оформления
кода (How), а не спецификация поведения — наблюдаемые требования к логам
(что система ОБЯЗАНА залогировать как часть контракта capability) живут в
OpenSpec-спеках (`### Requirement` с `SHALL`).

Краткая выжимка и инварианты — в [CLAUDE.md](../../CLAUDE.md), раздел
«Конвенции кода».

## Принципы

- Только `log/slog`, без `fmt.Println` и прямой записи в stdout.
- Структурированный JSON (`slog.JSONHandler`), один формат для dev и prod.
- Сообщение (`msg`) — константный шаблон/категория события; данные — в
  полях (атрибутах `slog`), а не в интерполяции текста.
- Каждое поле — отдельный ключ с типизированным значением. Это даёт
  фильтрацию и агрегацию через `jq`/DuckDB без регулярок.

```json
{"time":"2026-06-28T11:23:45.123456Z","level":"INFO","msg":"download accepted","capability":"ingest","download_id":"a1b2","infohash":"…","media_type":"movie","title":"Дюна: Часть вторая"}
```

## Сообщение

- `msg` — короткая константа в нижнем регистре: `download accepted`,
  `recognition done`, `layout failed`. Без переменных в тексте.
- Данные кладём в атрибуты: `slog.Info("download accepted", "download_id",
  id, "infohash", ih)`.

```go
// Правильно: msg — категория, данные — поля
log.Info("download accepted", "download_id", id, "media_type", "movie")

// Неправильно: данные зашиты в текст, агрегация ломается
log.Info(fmt.Sprintf("download %s accepted as movie", id))
```

- `msg` — чистая категория без неймспейс-префикса: `recognition done`, а не
  `recognize: done`. Подсистему выносим в поле `capability`
  (`ingest`/`recognition`/`file-layout`/`review`), не в текст.

## Уровни

Принцип: уровень — это **адресат** («кому сообщение»), а не «насколько
громко сломалось». `slog` даёт четыре уровня; их и используем.

| Уровень | Кому и когда | Примеры в jellybit |
|---|---|---|
| `DEBUG` | разработчику при отладке; в проде выключен | healthcheck-эндпоинты, поллинг статуса в qBittorrent, авто-рефреш UI, тела запросов/ответов внешних API, промежуточные шаги распознавания |
| `INFO`  | команде, аудит постфактум | приём загрузки, распознан фильм/сериал, раскладка выполнена, старт процессов, **событийный вызов внешнего сервиса** (по реальному действию) |
| `WARN`  | команде, «может стать проблемой» | retry внешнего вызова, низкая уверенность распознавания (ушло в ревью), приближение к лимиту |
| `ERROR` | команде, в техдолг / разбор | внешний сервис недоступен после ретраев, операция загрузки не выполнена, необработанная ошибка |

Правила:

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

## Время

- Поле — `time` (ключ по умолчанию `slog`).
- UTC, RFC 3339 с долями секунды, суффикс `Z`:
  `2026-06-28T11:23:45.123456Z`.
- Логи — **в UTC** (это явный TZ, не нарушает инвариант проекта): даёт
  однозначный порядок событий и лексикографическую сортировку. Бизнес-логика
  по-прежнему работает в `Europe/Moscow` — UTC только в логах.

## Поля: словарь имён

Главное условие — **единый словарь**: одно поле — одно имя по всему коду
(не `mediaType`/`media`/`media_type` вперемешку).

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

| Когда добавляем | Поля |
|---|---|
| на входящий HTTP-запрос (middleware) | `transport` (`http`/`web`/`telegram`), `http.method`, `http.route`, `http.status_code`, `duration_ms` |
| на загрузку (scoped-логгер, см. ниже) | `capability` (`ingest`/`recognition`/`file-layout`/`review`), `download_id`, `infohash`, `media_type`, `title` |
| на запись об ошибке | `error` |
| на вызов внешнего сервиса | `ext.service`, `ext.operation`, `ext.status_code`, `duration_ms`, `retry` |

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

## Корреляция по download_id

Отдельный случайный `trace_id` не заводим — у загрузки уже есть стабильный
осмысленный ключ: `download_id` (и `infohash`), он лежит в SQLite.

- Заводим scoped-логгер на загрузку и протаскиваем его через
  `context.Context` сквозь асинхронные стадии (приём → скачивание →
  распознавание → раскладка), чтобы ключ дописывался на каждую запись сам:

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

- Все записи одной загрузки собираются одним фильтром:
  `jq 'select(.download_id=="a1b2")' app.jsonl`.

## Ошибки

Go-ошибки логируем как атрибут, не как текст сообщения.

```go
// Правильно: msg — категория, ошибка — поле
log.Error("layout failed", "error", err, "download_id", id)

// Неправильно: ошибка зашита в msg, агрегация по событию ломается
log.Error(err.Error())
```

Правила:

- Ошибку передаём полем `"error", err` — не склеиваем в `msg`. Ключ —
  `error` (как по умолчанию в zap/zerolog; единый ключ важнее краткости).
- Идиома Go — **либо лог, либо возврат, не оба**. Промежуточные слои только
  оборачивают и возвращают (`fmt.Errorf("…: %w", err)`), не логируя —
  контекст накапливается в цепочке `%w`.
- Логируем ошибку **один раз — на границе доменного слоя** (use-case
  `Ingest`, стадии воркера), которая определяет исход операции: полем
  `error`, уровень `ERROR`. В Go логирует этот единый чокпоинт, а не каждый
  транспорт — так транспорты остаются тонкими.
- Транспорты (HTTP/web/Telegram) переводят возвращённую ошибку в свой ответ
  (статус, сообщение пользователю) и **не логируют** её повторно — иначе
  один сбой даёт дубли.
- Телеметрия внешнего вызова (`ext.*`, см. ниже) — отдельная запись о
  поведении зависимости, не дубль доменной ошибки.
- Глушить ошибку без лога — только с однострочным комментарием «почему».

## Внешние сервисы (обязательно логируем все вызовы)

**Каждый** вызов внешнего сервиса (qBittorrent, Jellyfin, LLM, TMDB/TVDB)
логируется. Поля:

- `ext.service` — `qbittorrent` / `jellyfin` / `llm` / `tmdb` / `tvdb`;
- `ext.operation` — логическая операция (`torrents/add`, `chat.completions`,
  `search/movie`);
- `ext.status_code` — HTTP-код ответа (если применимо);
- `duration_ms` — длительность вызова;
- `retry` — номер попытки (если были ретраи).

Уровни вызова:

- `INFO` — успешный **событийный** вызов (по реальному действию: добавление
  торрента, вызов LLM, рефреш Jellyfin, поиск в метабазе);
- `DEBUG` — успешный **рутинно-частый** вызов (поллинг статуса
  `torrents/info`/`torrents/files`, авто-рефреш) — см. правило «событийное →
  INFO, рутинно-частое → DEBUG» в разделе «Уровни»;
- `WARN` — попытка не удалась, делаем retry;
- `ERROR` — ретраи исчерпаны / сервис недоступен (сетевой сбой/таймаут).
  Завершённый HTTP-ответ с 4xx — это успех на транспортном уровне (`Success`
  с `ext.status_code`); решение «это ошибка» принимает доменный вызывающий.

Тело запроса/ответа — только на `DEBUG` и **после** вычистки секретов
(см. «Безопасность»).

## HTTP и healthcheck

- Входящие HTTP-запросы логируем с полями `http.method`, `http.route`,
  `http.status_code`, `duration_ms`, `transport` (`http`/`web`/`telegram`).
- Для корреляции HTTP-запроса допустим `request_id` (напр. chi `RequestID`) —
  это отдельный слой от корреляции загрузки по `download_id` и не противоречит
  отказу от `trace_id`. Если запрос порождает загрузку — связь даёт
  `download_id` в её записях.
- **Эндпоинты healthcheck/liveness/readiness логируем на `DEBUG`** — их
  дёргают периодически, на `INFO` они забивают аудит шумом. В проде
  (базовый уровень `INFO`) они не пишутся.

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

Никаких секретов в полях и сообщениях. Под запретом:

- учётные данные qBittorrent (логин/пароль, cookie сессии);
- API-ключ и токен LLM-провайдера, `Authorization`-заголовки;
- ключи TMDB/TVDB и прочих метабаз;
- содержимое аутентификационных параметров magnet/трекеров.

Дополнительно:

- Тела запросов/ответов внешних API и сырой вывод LLM (недоверенный, может
  быть большим) — только на `DEBUG`, с вычисткой секретов и обрезкой по длине.
- При сомнении — не логируем значение, логируем факт его наличия
  (`"has_api_key", true`).

## Куда пишем и уровень

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

## Анализ

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