From aac1b435af29efbe0c12428eda1d8f938bcb6ac3 Mon Sep 17 00:00:00 2001 From: Sergey Krylov Date: Fri, 14 Aug 2026 17:19:10 +0300 Subject: [PATCH] feat: add logging --- .../.openspec.yaml | 2 + .../design.md | 63 +++++++++++++++++ .../proposal.md | 28 ++++++++ .../specs/backend-structured-logging/spec.md | 68 ++++++++++++++++++ .../tasks.md | 25 +++++++ .../specs/backend-structured-logging/spec.md | 70 +++++++++++++++++++ 6 files changed, 256 insertions(+) create mode 100644 openspec/changes/archive/2026-08-14-add-backend-structured-logging/.openspec.yaml create mode 100644 openspec/changes/archive/2026-08-14-add-backend-structured-logging/design.md create mode 100644 openspec/changes/archive/2026-08-14-add-backend-structured-logging/proposal.md create mode 100644 openspec/changes/archive/2026-08-14-add-backend-structured-logging/specs/backend-structured-logging/spec.md create mode 100644 openspec/changes/archive/2026-08-14-add-backend-structured-logging/tasks.md create mode 100644 openspec/specs/backend-structured-logging/spec.md diff --git a/openspec/changes/archive/2026-08-14-add-backend-structured-logging/.openspec.yaml b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/.openspec.yaml new file mode 100644 index 0000000..4af8641 --- /dev/null +++ b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/.openspec.yaml @@ -0,0 +1,2 @@ +schema: spec-driven +created: 2026-08-14 diff --git a/openspec/changes/archive/2026-08-14-add-backend-structured-logging/design.md b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/design.md new file mode 100644 index 0000000..e360b3c --- /dev/null +++ b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/design.md @@ -0,0 +1,63 @@ +## Context + +См. `proposal.md` и `specs/backend-structured-logging/spec.md`. Backend NestJS сейчас использует встроенный `Logger` в T-Bank-, Portfolio- и Upcoming Events-сервисах, а глобальный exception filter формирует `application/problem+json`. Request context и единый JSON-формат отсутствуют. Конфигурация уже валидируется при запуске. + +## Goals / Non-Goals + +**Goals:** +- Один безопасный путь записи JSON-событий backend в stdout. +- Сквозной server-generated request ID для HTTP pipeline и T-Bank-клиента. +- Ровно одно HTTP completion-событие после фактической отправки ответа. +- Миграция существующих ручных логов на общий logger без изменения доменного поведения. + +**Non-Goals:** +- Настройка collector, поиска, retention, alerting или distributed tracing. +- Логирование Prisma query, HTTP-тел, заголовков и payload внешних сервисов. +- Browser telemetry, изменение response body или статусов API. + +## Decisions + +### Backend использует nestjs-pino + +Добавить `nestjs-pino` и настроить `LoggerModule` как единственный backend logger. Pino пишет JSON в stdout, реализует Nest `LoggerService` и создаёт request-scoped child logger. В bootstrap Nest использует `Logger` из `nestjs-pino` с буферизацией ранних framework-событий. + +`ConsoleLogger` с `json: true` отклонён: он не предоставляет request-scoped logger, HTTP hooks и redaction. Самописный logger отклонён: реализация формата, уровня, отказоустойчивого вывода и sanitization дублирует поддерживаемую библиотеку. + +### Контекст запроса хранится в AsyncLocalStorage + +`nestjs-pino` создаёт request-scoped logger и server-generated ID для каждого запроса. Middleware устанавливает этот ID в `X-Request-ID`; входящий ID сохраняется только отдельным валидированным `clientRequestId` и никогда не замещает server ID. `AsyncLocalStorage` остаётся минимальным способом передать внутренние user/account IDs в application-события без ручной передачи по всем вызовам. + +Контекст расширяется внутренними `userId` и `brokerageAccountId` в точке, где они уже получены. Данные не извлекаются из body или headers для логирования. T-Bank client читает текущий контекст, поэтому его события автоматически связываются с HTTP-запросом; вызов вне request context остаётся корректным, но без request ID. + +### Итог HTTP-запроса фиксируется через Pino на response finish + +`pino-http` создаёт request context и server-generated ID, но его automatic completion logging отключён: стандартный request serializer не знает безопасный route template и не должен журналировать headers. Response middleware измеряет duration и записывает через Pino одно allowlisted completion-событие с method, route template, status и request IDs. Это охватывает guards, validation и глобальный exception filter и отражает фактический status. + +Exception filter передаёт в безопасное response-local состояние только public error code и, для 5xx, stack exception. Completion logger выбирает уровень по status: info по умолчанию, warn для authentication failures и 429, error для 5xx. Отдельные error-события HTTP не создаются. + +Interceptor отклонён, потому что требует отдельной обработки Observable errors и не покрывает каждый Express response столь же надёжно. Логирование полного исходного URL отклонено из-за query data и высокой cardinality. + +### События используют allowlist полей + +Pino redaction запрещает секретные request fields, а custom serializers передают только allowlisted HTTP context. Для T-Bank application-событий записываются operation, duration, gRPC code и attempts; для доменных событий - внутренние IDs и безопасные счётчики. Секретные, прямые персональные, финансовые и upstream payload значения не передаются API logger. + +Allowlist выбран вместо generic redaction: запрет на запись опасного поля надёжнее, чем надежда распознать все формы токенов и вложенных payload. В частности, существующие logs Upcoming Events будут сокращены до разрешённых ID и счётчиков, без ticker, FIGI, display name и дат/сумм событий. + +### T-Bank client создаёт события в границах RPC + +Общий вызов RPC измеряет каждый завершённый запрос. Успех записывается как debug; решение о retry - как warn; окончательный отказ - как error с gRPC code и числом попыток. В лог не передаются request object, metadata или token. Существующая семантика retry, deadline, rate limit и преобразования ошибок сохраняется. + +## Risks / Trade-offs + +- [Незаполненный route template в раннем Express failure] -> Использовать безопасный fallback без query string и покрыть его интеграционным тестом. +- [Контекст теряется в новом async boundary] -> Logger допускает отсутствие request ID; для каждого нового background runner явно создавать свой context. +- [Ошибка записи JSON stdout] -> Pino изолирует вывод от business flow; проверить это unit-тестом интеграции logger. +- [Debug T-Bank события увеличат объём вывода] -> `LOG_LEVEL=info` в production по умолчанию; debug включается временно при диагностике. + +## Migration Plan + +1. Добавить `nestjs-pino`, валидируемый `LOG_LEVEL`, Pino configuration и request context middleware. +2. Подключить Pino в bootstrap, CORS expose header и HTTP completion logging вместе с exception filter metadata. +3. Перевести T-Bank client, Portfolio и Upcoming Events на allowlisted события; удалить прямое использование Nest `Logger` в них. +4. Добавить unit и e2e проверки уровня, безопасности полей, request ID, CORS и уровней HTTP/T-Bank событий. +5. Выпустить с `LOG_LEVEL=info`, проверить JSON stdout и `X-Request-ID`; rollback состоит в откате backend release, так как данных и контрактов request body нет. diff --git a/openspec/changes/archive/2026-08-14-add-backend-structured-logging/proposal.md b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/proposal.md new file mode 100644 index 0000000..509c44b --- /dev/null +++ b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/proposal.md @@ -0,0 +1,28 @@ +## Зачем + +Текущие точечные backend-логи не имеют единого формата и сквозной связи с HTTP-запросом, поэтому ошибки API и вызовов T-Bank трудно диагностировать. Нужны безопасные структурированные события, которые позволяют связать ответ клиенту с обработкой запроса и внешней интеграцией без записи секретов или финансовых данных. + +## Что меняется + +- Ввести единый JSON-формат backend-логов в stdout для lifecycle-событий, HTTP-запросов, авторизации, доменных сервисов и вызовов T-Bank. +- Генерировать server-side request ID для каждого HTTP-запроса, передавать его в связанные события и возвращать клиенту в `X-Request-ID` через CORS. +- Установить уровни и обязательный безопасный контекст для HTTP- и T-Bank-событий, включая стабильный public error code для ошибок. +- Исключить из логов секреты, HTTP-тела, заголовки, прямые персональные и финансовые данные; разрешить только внутренние идентификаторы пользователя и брокерского счёта. +- Добавить валидируемую конфигурацию `LOG_LEVEL` и мигрировать существующие ручные backend-логи на общую схему. + +## Возможности + +### Новые возможности +- `backend-structured-logging`: безопасные структурированные backend-логи, сквозная корреляция HTTP-запросов и событий T-Bank. + +### Изменяемые возможности + +_Нет._ + +## Влияние + +- Backend: bootstrap, HTTP pipeline, CORS, exception handling, auth, T-Bank client и сервисы с существующими ручными логами. +- Зависимости: `nestjs-pino` для JSON-вывода, request-scoped logger и интеграции с Nest. +- Конфигурация: новая валидируемая переменная окружения `LOG_LEVEL`. +- API: response header `X-Request-ID` становится доступным browser-клиенту через CORS; тело и status существующих ответов не меняются. +- Инфраструктура: backend пишет JSON в stdout; collector, хранение, alerting и frontend telemetry не входят в это изменение. diff --git a/openspec/changes/archive/2026-08-14-add-backend-structured-logging/specs/backend-structured-logging/spec.md b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/specs/backend-structured-logging/spec.md new file mode 100644 index 0000000..9562700 --- /dev/null +++ b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/specs/backend-structured-logging/spec.md @@ -0,0 +1,68 @@ +## Purpose + +Определяет безопасные структурированные backend-логи, позволяющие связать HTTP-запрос, его ответ и вызовы T-Bank при диагностике инцидентов. + +## ADDED Requirements + +### Requirement: Backend публикует единообразные структурированные события +Backend SHALL записывать lifecycle-, HTTP-, authentication-, domain- и T-Bank-события в stdout как Pino JSON-записи с time, level, message и безопасным context. Записи MUST поддерживать уровни debug, info, warn и error; уровень вывода MUST настраиваться валидируемой конфигурацией `LOG_LEVEL` с production-значением по умолчанию `info`. + +#### Scenario: Приложение успешно запускается +- **WHEN** backend завершает запуск +- **THEN** stdout содержит info JSON-событие запуска с безопасными service и environment + +#### Scenario: Выбран уровень debug +- **WHEN** backend запущен с допустимым `LOG_LEVEL=debug` +- **THEN** stdout содержит debug-события наряду с событиями более высоких уровней + +#### Scenario: Указан недопустимый уровень логирования +- **WHEN** backend запущен с недопустимым значением `LOG_LEVEL` +- **THEN** запуск завершается ошибкой валидации конфигурации + +### Requirement: HTTP-запросы имеют сквозной идентификатор +Backend SHALL создавать server-generated request ID для каждого HTTP-запроса, включать его в связанные с запросом log-события и возвращать его в response header `X-Request-ID`. CORS MUST разрешать browser-клиенту прочитать этот header. Входящий request ID MAY быть записан отдельным недоверенным полем, но MUST NOT заменять server-generated request ID и MUST NOT влиять на авторизацию или обработку запроса. + +#### Scenario: Клиент получает идентификатор запроса +- **WHEN** browser-клиент получает HTTP-ответ backend +- **THEN** ответ содержит `X-Request-ID`, доступный через CORS, и этот же ID присутствует в HTTP log-событии + +#### Scenario: Клиент передаёт собственный идентификатор +- **WHEN** HTTP-запрос содержит client-provided request ID +- **THEN** backend использует другой server-generated request ID для обработки и логирования запроса + +### Requirement: Backend фиксирует итог каждого HTTP-запроса +Backend SHALL записывать ровно одно completion-событие для каждого HTTP-запроса с request ID, HTTP method, route template, status и duration. Completion-событие MUST иметь level info для обычных ответов, warn для authentication failures и status 429, error для status 5xx. События с ошибкой MUST включать стабильный public error code; error-события для status 5xx MUST включать stack trace. + +#### Scenario: Запрос завершается успешно +- **WHEN** backend возвращает ответ со status 2xx +- **THEN** stdout содержит одно info completion-событие с route template без query string и длительностью обработки + +#### Scenario: T-Bank недоступен во время запроса +- **WHEN** backend возвращает клиенту status 503 с public error code `TBANK_UNAVAILABLE` +- **THEN** stdout содержит одно error completion-событие с этим code, request ID и stack trace + +#### Scenario: Запрос не проходит аутентификацию +- **WHEN** backend возвращает status 401 или 403 +- **THEN** stdout содержит одно warn completion-событие без отдельного дублирующего события ошибки + +### Requirement: События T-Bank позволяют диагностировать интеграцию +Backend SHALL записывать события вызовов T-Bank с request ID, именем операции и duration, когда вызов выполняется в контексте HTTP-запроса. Успешный вызов MUST иметь level debug, повтор вызова MUST иметь level warn, а окончательный сбой MUST иметь level error и содержать gRPC code и число попыток. + +#### Scenario: Вызов T-Bank успешен с первой попытки +- **WHEN** вызов T-Bank завершается успешно без повтора +- **THEN** stdout содержит debug-событие операции с её duration и request ID + +#### Scenario: Вызов T-Bank повторяется и затем завершается ошибкой +- **WHEN** вызов T-Bank исчерпывает разрешённые попытки +- **THEN** stdout содержит warn-событие повтора и error-событие окончательного сбоя с gRPC code и числом попыток + +### Requirement: Логи не раскрывают секретные и чувствительные данные +Backend MUST NOT записывать в логи token, cookie, JWT, пароль, полный HTTP header, HTTP body, email, IP-адрес, финансовые значения или payload T-Bank. В production-логах MAY присутствовать только внутренние user ID и brokerage account ID, если они известны при формировании события. Ошибка формирования или вывода log-события MUST NOT менять HTTP-ответ или результат доменной операции. + +#### Scenario: Запрос содержит секретные данные +- **WHEN** HTTP-запрос содержит authentication cookie, JWT или тело с паролем +- **THEN** связанные log-события не содержат эти значения + +#### Scenario: Событие не сериализуется +- **WHEN** backend не может сериализовать поле log-события +- **THEN** backend завершает обработку исходного запроса без ошибки, вызванной логированием diff --git a/openspec/changes/archive/2026-08-14-add-backend-structured-logging/tasks.md b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/tasks.md new file mode 100644 index 0000000..4bcfd8a --- /dev/null +++ b/openspec/changes/archive/2026-08-14-add-backend-structured-logging/tasks.md @@ -0,0 +1,25 @@ +## 1. Базовый logger и конфигурация + +- [x] 1.1 Добавить валидируемый `LOG_LEVEL`, его production default и пример в backend-конфигурацию. +- [x] 1.2 Добавить `nestjs-pino`, настроить JSON stdout, уровни debug/info/warn/error, redaction и allowlisted HTTP serializers. +- [x] 1.3 Подключить Pino к Nest bootstrap с lifecycle-событиями запуска и штатного завершения. + +## 2. Контекст и HTTP-события + +- [x] 2.1 Добавить request context на `AsyncLocalStorage`: server-generated request ID, безопасный client request ID и `X-Request-ID` response header. +- [x] 2.2 Настроить CORS для чтения `X-Request-ID` browser-клиентом. +- [x] 2.3 Добавить единственное HTTP completion-событие с безопасным route template, duration и уровнем по outcome. +- [x] 2.4 Передавать public error code и stack 5xx из exception filter в completion-событие без изменения problem response. + +## 3. Миграция backend-событий + +- [x] 3.1 Перевести T-Bank client на allowlisted success/retry/failure события с duration, gRPC code и attempts. +- [x] 3.2 Перевести существующие Portfolio и Upcoming Events события на Pino logger и удалить прямой `Nest Logger`. +- [x] 3.3 Добавить внутренние user ID и brokerage account ID в контекст только в местах, где они уже доступны. + +## 4. Проверка + +- [x] 4.1 Добавить unit-тесты logger и config validation для уровней, JSON-формата и отсутствия запрещённых полей. +- [x] 4.2 Добавить backend e2e-тесты `X-Request-ID`, CORS, одного completion-события, 5xx error code/stack и безопасной деградации logging failure. +- [x] 4.3 Добавить тесты T-Bank client для уровней success/retry/final failure и correlation context. +- [x] 4.4 Выполнить `npm run lint`, `npm test`, `npm run build` в backend и `openspec validate add-backend-structured-logging --type change --store wealth-ledger-specs`. diff --git a/openspec/specs/backend-structured-logging/spec.md b/openspec/specs/backend-structured-logging/spec.md new file mode 100644 index 0000000..5499462 --- /dev/null +++ b/openspec/specs/backend-structured-logging/spec.md @@ -0,0 +1,70 @@ +# backend-structured-logging Specification + +## Purpose + +Определяет безопасные структурированные backend-логи, позволяющие связать HTTP-запрос, его ответ и вызовы T-Bank при диагностике инцидентов. + +## Requirements + +### Requirement: Backend публикует единообразные структурированные события +Backend SHALL записывать lifecycle-, HTTP-, authentication-, domain- и T-Bank-события в stdout как Pino JSON-записи с time, level, message и безопасным context. Записи MUST поддерживать уровни debug, info, warn и error; уровень вывода MUST настраиваться валидируемой конфигурацией `LOG_LEVEL` с production-значением по умолчанию `info`. + +#### Scenario: Приложение успешно запускается +- **WHEN** backend завершает запуск +- **THEN** stdout содержит info JSON-событие запуска с безопасными service и environment + +#### Scenario: Выбран уровень debug +- **WHEN** backend запущен с допустимым `LOG_LEVEL=debug` +- **THEN** stdout содержит debug-события наряду с событиями более высоких уровней + +#### Scenario: Указан недопустимый уровень логирования +- **WHEN** backend запущен с недопустимым значением `LOG_LEVEL` +- **THEN** запуск завершается ошибкой валидации конфигурации + +### Requirement: HTTP-запросы имеют сквозной идентификатор +Backend SHALL создавать server-generated request ID для каждого HTTP-запроса, включать его в связанные с запросом log-события и возвращать его в response header `X-Request-ID`. CORS MUST разрешать browser-клиенту прочитать этот header. Входящий request ID MAY быть записан отдельным недоверенным полем, но MUST NOT заменять server-generated request ID и MUST NOT влиять на авторизацию или обработку запроса. + +#### Scenario: Клиент получает идентификатор запроса +- **WHEN** browser-клиент получает HTTP-ответ backend +- **THEN** ответ содержит `X-Request-ID`, доступный через CORS, и этот же ID присутствует в HTTP log-событии + +#### Scenario: Клиент передаёт собственный идентификатор +- **WHEN** HTTP-запрос содержит client-provided request ID +- **THEN** backend использует другой server-generated request ID для обработки и логирования запроса + +### Requirement: Backend фиксирует итог каждого HTTP-запроса +Backend SHALL записывать ровно одно completion-событие для каждого HTTP-запроса с request ID, HTTP method, route template, status и duration. Completion-событие MUST иметь level info для обычных ответов, warn для authentication failures и status 429, error для status 5xx. События с ошибкой MUST включать стабильный public error code; error-события для status 5xx MUST включать stack trace. + +#### Scenario: Запрос завершается успешно +- **WHEN** backend возвращает ответ со status 2xx +- **THEN** stdout содержит одно info completion-событие с route template без query string и длительностью обработки + +#### Scenario: T-Bank недоступен во время запроса +- **WHEN** backend возвращает клиенту status 503 с public error code `TBANK_UNAVAILABLE` +- **THEN** stdout содержит одно error completion-событие с этим code, request ID и stack trace + +#### Scenario: Запрос не проходит аутентификацию +- **WHEN** backend возвращает status 401 или 403 +- **THEN** stdout содержит одно warn completion-событие без отдельного дублирующего события ошибки + +### Requirement: События T-Bank позволяют диагностировать интеграцию +Backend SHALL записывать события вызовов T-Bank с request ID, именем операции и duration, когда вызов выполняется в контексте HTTP-запроса. Успешный вызов MUST иметь level debug, повтор вызова MUST иметь level warn, а окончательный сбой MUST иметь level error и содержать gRPC code и число попыток. + +#### Scenario: Вызов T-Bank успешен с первой попытки +- **WHEN** вызов T-Bank завершается успешно без повтора +- **THEN** stdout содержит debug-событие операции с её duration и request ID + +#### Scenario: Вызов T-Bank повторяется и затем завершается ошибкой +- **WHEN** вызов T-Bank исчерпывает разрешённые попытки +- **THEN** stdout содержит warn-событие повтора и error-событие окончательного сбоя с gRPC code и числом попыток + +### Requirement: Логи не раскрывают секретные и чувствительные данные +Backend MUST NOT записывать в логи token, cookie, JWT, пароль, полный HTTP header, HTTP body, email, IP-адрес, финансовые значения или payload T-Bank. В production-логах MAY присутствовать только внутренние user ID и brokerage account ID, если они известны при формировании события. Ошибка формирования или вывода log-события MUST NOT менять HTTP-ответ или результат доменной операции. + +#### Scenario: Запрос содержит секретные данные +- **WHEN** HTTP-запрос содержит authentication cookie, JWT или тело с паролем +- **THEN** связанные log-события не содержат эти значения + +#### Scenario: Событие не сериализуется +- **WHEN** backend не может сериализовать поле log-события +- **THEN** backend завершает обработку исходного запроса без ошибки, вызванной логированием