Files
ds-galo/openspec/changes/archive/2026-10-11-add-observability-logging/design.md
T
iu 6361e48b20 feat(observability): configurable logging, request ids and error logs
- internal/logging: LOG_LEVEL/LOG_FORMAT parsing and slog handler
- request_id middleware (X-Request-ID or generated, echoed) + debug access log
- httpx registers errors; middleware logs internal causes with request_id
- health excluded, objects/sse debug-only, no query/body/secrets in logs
- new observability capability spec; README/.env.example docs
2026-10-11 13:40:11 +03:00

113 lines
7.2 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# Design
## Context
См. `proposal.md` — Why. Текущее состояние, важное для подхода:
- Логирование инициализируется в `backend/cmd/server/main.go:34` жёстко
(`slog.NewJSONHandler(os.Stdout, LevelInfo)`), без чтения конфига.
- Роутер — `gin.New()` + `gin.Recovery()` (`internal/app/app.go:94`); access-логов,
`request_id` и middleware корреляции нет. Есть только `auth.Middleware` на группе `/api`
(`app.go:122`).
- `httpx.RespondError`/`Abort` (`internal/httpx/httpx.go:55-71`) для не-`AppError`
отвечают generic `500` и не логируют причину.
- `slog` уже используется точечно (`internal/db/db.go`, `internal/photos/worker.go`),
версия Go 1.26, `gin v1.12`.
## Goals / Non-Goals
**Goals:**
- Управляемые уровень и формат логов без изменения кода.
- Один след на запрос: `request_id` во всех строках, порождённых этим запросом.
- Видимость причины внутренних ошибок в логах.
- Отсутствие утечки секретов (токены, пароли, query, тела, подписанные URL).
**Non-Goals:**
- Доменные (операционные) логи в сервисах (`album.created`, `photo.uploaded`) — слой C,
не входит.
- Метрики, трейсинг, экспорт во внешние системы.
- Изменение CLI-команд (`migrate`, `reconcile`, `backfill-exif`).
- Изменение формата ответов API.
## Decisions
### D1. Конфигурация уровня и формата
Новые env `LOG_LEVEL` (`debug|info|warn|error`, default `info`) и `LOG_FORMAT`
(`json|text`, default `json`). Значения валидируются в `config.Load`; недопустимое
значение — ошибка старта. `main.go` строит handler из конфига.
- Альтернатива: булев `GALO_DEBUG` — отклонено, слишком грубо (нет warn/error отдельно)
и не даёт формат.
- Новый пакет `internal/logging` инкапсулирует разбор уровня и сборку handler
(`NewHandler(format, level)`), чтобы не размазывать `slog`-детали по `config` и `main`.
### D2. Идентификатор запроса
Middleware (B) берёт `X-Request-ID` из входящего запроса, если он корректной формы
(ограничение длины и допустимые символы), иначе генерирует новый. `request_id`:
- кладётся в `context.Context` запроса (`logging.WithRequestID`);
- возвращается клиенту в заголовке ответа `X-Request-ID`.
Так связка «запрос клиента ↔ строка в логе» работает без доступа к внутреннему состоянию.
- Альтернатива: не принимать клиентский id и всегда генерировать — проще, но теряет
сквозную корреляцию с внешним прокси. Выбрано «принять валидный, иначе сгенерировать».
### D3. Логирование внутренних ошибок
`httpx.RespondError`/`Abort` перестают молча выдавать `500`: для ошибки, не являющейся
`*AppError`, они вызывают `c.Error(err)` (gin накапливает, не пишет ответ). Middleware (B)
после `c.Next()` записывает все собранные ошибки на уровне `error` с причиной и `request_id`.
- Классификация: `*AppError` со статусом `< 500` → `debug`; `*AppError` со статусом `>= 500`
и любая не-`AppError` → `error`.
- Альтернатива: логировать прямо в `httpx` через `slog.ErrorContext` — меньше правок, но
два независимых места логирования и дублирование `request_id`. Выбрана централизация в
middleware.
- `log/slog` не имеет контекстных атрибутов «из коробки»; `request_id` подставляется
явно из `logging.RequestID(ctx)`.
### D4. Access-лог
Один middleware в `app.Router()` до групп маршрутов; после `c.Next()` пишет строку
уровня `debug`: `method`, `route` (`c.FullPath()`, **без query**), `status`, `latency`,
`bytes`, `client_ip`, `user_id` (`auth.UserID`, если установлен), `request_id`.
- `user_id` доступен, т.к. middleware оборачивает `auth.Middleware` и читает контекст
после завершения цепочки.
### D5. Уровни (сводно)
| Событие | Уровень |
|---|---|
| Старт, бэкенды, миграции, storage ready (как сейчас) | info |
| Причина внутренней ошибки (не-`AppError`, 5xx) | error |
| Access-строка запроса | debug |
| Отказ 4xx (`AppError < 500`) | debug |
### D6. Фильтрация и приватность
- `/api/health` — всегда исключён из access-лога.
- `/api/objects/*` и `/api/sse/*` — access-логи только на `debug` (объём/долгие соединения).
- Никогда не логируются: query-строка целиком (там `?token=` для SSE), подписанные URL,
заголовок `Authorization`, тела запросов, пароли.
## Risks / Trade-offs
- [Рост объёма на `debug` от `/api/objects/*` и SSE] -> фильтры из D6; на `info`
объём не растёт (access/4xx — `debug`).
- [Спуфинг `X-Request-ID` клиентом] -> принимаем только валидную форму с ограничением
длины; иначе генерируем.
- [Ложная latency для SSE (весь срок соединения)] -> SSE-строки только на `debug`;
поле трактуется как длительность соединения.
- [Утечка секретов через логи] -> D6 запрещает query/body/Authorization; явные поля — только
route и метаданные.
- [Двойной ответ при `c.Error`] -> `c.Error` только регистрирует ошибку, ответ уже
отправлен `httpx`; middleware лишь читает `c.Errors`.
## Migration Plan
Изменение кода и конфигурации, без миграции данных. При отсутствии новых env поведение
соответствует `LOG_LEVEL=info`, `LOG_FORMAT=json` — обычные логи почти не меняются. Для
диагностики выставить `LOG_LEVEL=debug`. Откат — вернуть прежний жёсткий handler.
## Open Questions
Нет.