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

7.2 KiB
Raw Blame History

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

Нет.