food-market/docs/logging.md
nns 443eebe862 feat(logging): структурные log-fields в Serilog (TD-4)
LogEnrichmentMiddleware: после Authentication+Authorization вытягивает из
ClaimsPrincipal OrgId (claim org_id) и UserId (sub/NameIdentifier), плюс
CorrelationId из заголовка X-Correlation-ID (или генерирует Guid). Все три
кладутся в Serilog LogContext через PushProperty — каждая ILogger.Log*
внутри пайплайна автоматически получает эти поля как структурные
properties (не текст), пригодные для фильтрации в Loki/ELK без regex.

Эхо CorrelationId в response-header — клиент видит id для support.

Business-логи (структурные плейсхолдеры, не string interpolation):
- Supply.Post → "Supply posted: {SupplyNumber} supplier={SupplierId}
  store={StoreId} lines={LinesCount} total={Total}".
- RetailSale.Post → "RetailSale posted: {SaleNumber} store={StoreId}
  payment={Payment} lines={LinesCount} total={Total}".

docs/logging.md — паттерн, anti-pattern'ы (string interpolation, PII в
логах, токены/пароли), correlation-id workflow.

Co-Authored-By: Claude Opus 4.7 <noreply@anthropic.com>
2026-05-28 17:46:17 +05:00

3.9 KiB
Raw Permalink Blame History

Логирование (Serilog)

Структурные логи через Serilog. На каждый HTTP-запрос автоматически обогащаются метки CorrelationId, OrgId, UserId через LogEnrichmentMiddleware. Любой ILogger<…>.Log* внутри пайплайна наследует эти свойства — не нужно тащить их в каждый вызов руками.

Где приземляются логи

Текущая конфигурация (см. appsettings.json / Program.cs):

  • Console (Serilog.Sinks.Console) — в dev и docker (stdout читается docker logs / journalctl);
  • File (Serilog.Sinks.File) — ротация по дням.

Для прод-ELK/Loki в будущем добавляется Serilog.Sinks.Elasticsearch или Serilog.Sinks.Grafana.Loki; формат вывода уже JSON-friendly, кардинальность лейблов под Loki не вылезает (OrgId гранулярный, но не на каждое движение, плюс ограничен текущим парком орг ≪10k).

Корреляция между запросами

Заголовок X-Correlation-ID:

  • если клиент прислал — middleware его уважает (для bridging с upstream'ом);
  • если нет — генерируется Guid.NewGuid("N").

Эхо в response-header чтобы клиент при ошибке отдал support'у конкретный id.

curl -i http://localhost:5081/api/me -H "Authorization: Bearer …"
# < X-Correlation-ID: 7f9b3c1a4e5d4f0a8b1c2d3e4f5a6b7c

Структурные бизнес-логи

В коде используем именованные плейсхолдеры — Serilog кладёт каждое поле как отдельное property в LogEvent. Это позволяет фильтровать OrgId = "..." AND SupplyNumber = "..." без regex'ов.

Хорошо:

_log.LogInformation(
    "Supply posted: {SupplyNumber} supplier={SupplierId} store={StoreId} lines={LinesCount} total={Total}",
    supply.Number, supply.SupplierId, supply.StoreId, supply.Lines.Count, supply.Total);

Плохо (теряем структуру, нельзя фильтровать):

_log.LogInformation($"Supply posted: {supply.Number} ...");  // string interpolation

Что уже логируется как business event

  • Supply posted — после успешного /api/purchases/supplies/{id}/post.
  • RetailSale posted — после успешного /api/sales/retail/{id}/post.

В развитии: Demand.Post, Transfer.Post, Inventory.Post, Loss.Post — по тому же паттерну. Метки разные, имя события одинаковое для аналитики «сколько проведений в час по типам».

Запросы (Serilog request logging)

app.UseSerilogRequestLogging() пишет одну summary-строку на каждый HTTP-запрос: метод, путь, статус, длительность. Дополнительно обогащается OrgId/UserId/CorrelationId из LogContext.

Шаблон в логе:

HTTP POST /api/purchases/supplies/{id}/post responded 204 in 87.3ms
{ OrgId: "8b0f...", UserId: "57c3...", CorrelationId: "7f9b..." }

Анти-паттерны

  • Не логировать токены/пароли/email-пароли — даже структурно. Identity events (SignIn / Reset Password) — нет, только статус и user-id.
  • Не логировать тело запроса целиком — может содержать PII. Только конкретные поля по необходимости.
  • Не использовать string interpolation в шаблоне — теряется структура (выше).