feat: add logging
This commit is contained in:
@@ -0,0 +1,2 @@
|
|||||||
|
schema: spec-driven
|
||||||
|
created: 2026-08-14
|
||||||
@@ -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 нет.
|
||||||
@@ -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 не входят в это изменение.
|
||||||
+68
@@ -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 завершает обработку исходного запроса без ошибки, вызванной логированием
|
||||||
@@ -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`.
|
||||||
@@ -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 завершает обработку исходного запроса без ошибки, вызванной логированием
|
||||||
Reference in New Issue
Block a user