Структурированные логи в NestJS: pino, контекст запроса и защита персональных данных

← назад к разделу

Представьте: приложение падает в два часа ночи. Вы открываете логи и видите тысячи строк вроде Order confirmed: {"id":"abc","items":[...],"userId":...}. Найти момент, когда всё пошло не так, — задача на несколько часов.

Теперь другая картина: каждая строка лога — это JSON с полями orderId, trace_id, userId. Вы фильтруете по orderId в Loki за секунду и восстанавливаете всю цепочку событий.

Разница — в структурированных логах. В NestJS это делается через nestjs-pino.

Почему console.log не работает в продакшне

console.log пишет неструктурированный текст. У этой записи нет полей — её нельзя отфильтровать по userId или orderId. Она не знает, к какому HTTP-запросу относится. Нет уровня серьёзности, нет идентификатора трассировки.

Системы сбора логов (Loki, ELK, Datadog) умеют разбирать JSON. Если лог — это JSON-объект, каждое поле становится фильтром. Если это свободный текст — нужен regex, который ломается при малейшем изменении формата.

nestjs-pino — это интеграция pino с NestJS. Pino — один из самых быстрых логгеров для Node.js: он буферизует вывод и сериализует объекты только тогда, когда нужно.

Настройка: JSON в продакшне, цветной вывод локально

Первый шаг — подключить nestjs-pino в корневом модуле:

// app.module.ts
import { LoggerModule } from 'nestjs-pino';
import { randomUUID } from 'crypto';

@Module({
  imports: [
    LoggerModule.forRoot({
      pinoHttp: {
        transport:
          process.env.NODE_ENV !== 'production'
            ? { target: 'pino-pretty', options: { colorize: true, translateTime: 'HH:MM:ss' } }
            : undefined,
        level: process.env.LOG_LEVEL ?? 'info',
        redact: ['req.headers.authorization', '*.password', '*.email', '*.phone'],
        genReqId: (req) =>
          (req.headers['x-request-id'] as string) ?? randomUUID(),
        autoLogging: true,
      },
    }),
  ],
})
export class AppModule {}

Что здесь происходит:

• В development — pino-pretty форматирует вывод с цветами и человекочитаемым временем. Локально это удобнее.
• В production — никакого форматирования. Pino пишет JSON одной строкой на каждое событие. Loki и ELK разбирают его без дополнительных правил.
• redact — список путей, которые pino автоматически заменит на [Redacted] перед записью. Это защита на случай, если где-то в коде персональные данные попадут в объект, который передан в логгер.
• genReqId — берёт X-Request-Id из заголовка или генерирует новый UUID. Этот идентификатор будет присутствовать в каждой записи, связанной с запросом.
• autoLogging: true — pino сам пишет access-log на каждый HTTP-запрос: метод, путь, статус, время ответа.

DI-логгер вместо new Logger()

В NestJS логгер получают через Dependency Injection — так же, как любой другой сервис:

// order.service.ts
import { Injectable } from '@nestjs/common';
import { InjectPinoLogger, PinoLogger } from 'nestjs-pino';

@Injectable()
export class OrderService {
  constructor(
    @InjectPinoLogger(OrderService.name)
    private readonly logger: PinoLogger,
    private readonly orderRepository: OrderRepository,
  ) {}

  async confirm(orderId: string): Promise<Order> {
    this.logger.info({ orderId }, 'confirming order');
    const order = await this.orderRepository.findById(orderId);
    order.confirm();
    return this.orderRepository.save(order);
  }
}

@InjectPinoLogger(OrderService.name) передаёт имя класса в логгер — оно появится в каждой записи как поле context. Если класс переименуют при рефакторинге, поле обновится автоматически.

Создавать логгер через new Logger() или использовать console — плохая практика: такой логгер не знает о текущем запросе и не добавит requestId и trace_id в записи.

Структурные поля вместо строк

Самая частая ошибка — передавать данные через шаблонную строку:

// Плохо: JSON.stringify выполняется всегда, даже если уровень отключён
this.logger.info(`Order created: ${JSON.stringify(order)}`);

// Хорошо: pino сериализует объект только при активном уровне
this.logger.info({ orderId: order.id, customerId: order.customerId }, 'order created');

Когда данные передаются первым аргументом как объект, pino добавляет каждое поле на верхний уровень JSON-записи. Это позволяет фильтровать логи по orderId напрямую, без regex.

При отключённом уровне (например, debug в продакшне) pino не сериализует объект вообще — это экономия CPU на горячих путях.

Уровни: когда что использовать

Выбор уровня — это не формальность. От него зависит, что попадёт в алерты:

// Примеры правильного использования уровней
this.logger.error({ err, orderId }, 'payment charge failed');
this.logger.warn({ orderId, attempt }, 'payment provider retry');
this.logger.info({ orderId, amount: order.amount }, 'order confirmed');
this.logger.debug({ orderState: order }, 'aggregate state after confirm');

Важный момент: autoLogging: true уже пишет access-log на каждый HTTP-запрос. Добавлять info в каждый метод контроллера — лишний шум. Уровень info внутри handler-а нужен только для критичных операций вроде платежа.

requestId и trace_id в каждой записи

Самое ценное в nestjs-pino — это то, что логгер знает о текущем HTTP-запросе. Под капотом он использует AsyncLocalStorage: хранилище, которое живёт в рамках одного запроса и доступно из любой функции в его цепочке вызовов.

Каждая запись автоматически получает:

• req.id — идентификатор запроса из X-Request-Id или сгенерированный UUID.
• trace_id и span_id — при установленном @opentelemetry/instrumentation-pino добавляются автоматически.
• userId — добавляется после проверки JWT:

// auth.guard.ts
@Injectable()
export class JwtAuthGuard implements CanActivate {
  constructor(@InjectPinoLogger() private readonly logger: PinoLogger) {}

  async canActivate(context: ExecutionContext): Promise<boolean> {
    const request = context.switchToHttp().getRequest();
    const payload = this.verifyToken(request.headers.authorization);
    this.logger.assign({ userId: payload.sub });
    return true;
  }
}

logger.assign({ userId }) добавляет поле в текущий AsyncLocalStorage-контекст. Все последующие логи в рамках этого запроса — из сервиса, репозитория, внешнего клиента — автоматически получат userId.

В итоге запись в Loki выглядит так:

{
  "time": "2026-05-25T22:30:00.123Z",
  "level": "info",
  "context": "OrderService",
  "msg": "order confirmed",
  "req": { "id": "0193a8f3-7c21-7e3f-9b4a-..." },
  "trace_id": "5e92c8a3b1f4d2e6a7c8e9f0a1b2c3d4",
  "userId": "user-42",
  "orderId": "order-789",
  "amount": 4990
}

По trace_id можно восстановить полную цепочку вызовов через трассировку. По orderId — найти все события, связанные с конкретным заказом.

Где логировать: границы сервиса

Логи нужны на границах — там, где сервис общается с внешним миром:

Входящие HTTP-запросы — autoLogging уже пишет access-log. Добавлять info нужно только для критичных команд:

@Post(':id/confirm')
async confirmOrder(@Param('id') orderId: string): Promise<void> {
  this.logger.info({ orderId }, 'confirm order request received');
  await this.confirmOrderUseCase.execute({ orderId });
}

Исходящие HTTP-запросы — логировать вызов и результат:

async charge(orderId: string, amount: number): Promise<ChargeResult> {
  this.logger.info({ orderId, amount }, 'calling payment provider charge');
  try {
    const result = await this.http.post('/charge', { orderId, amount });
    return result.data;
  } catch (err) {
    this.logger.error({ err, orderId }, 'payment provider charge failed');
    throw err;
  }
}

Фоновые задачи — логировать начало и конец с количеством обработанных записей:

async process(job: Job): Promise<void> {
  this.logger.info({ jobId: job.id }, 'outbox relay started');
  const count = await this.relay.publish();
  this.logger.info({ jobId: job.id, count }, 'outbox relay completed');
}

В середине бизнес-логики логи нужны только тогда, когда принято важное решение или произошла деградация. Запись «Entering method» или «Loaded N rows» — это шум, который мешает найти нужное.

Персональные данные в логах

Персональные данные в логах — это серьёзная проблема: они попадают в системы хранения логов, к которым может быть широкий доступ, их трудно удалить и они нарушают требования по защите данных.

Правило простое: email, телефон, ФИО, адрес, токены, пароли — никогда в логах в открытом виде.

// Плохо — email и телефон в логах
this.logger.info(
  { email: user.email, phone: user.phone },
  'customer registered',
);

// Хорошо — только внутренний идентификатор
this.logger.info({ customerId: user.id }, 'customer registered');

// Хорошо — маскировать, если контекст нужен для расследования
this.logger.info(
  { customerId: user.id, emailMask: maskEmail(user.email) },
  'email verification sent',
);
// maskEmail('john@example.com') → 'j***@example.com'

redact в конфигурации — второй рубеж защиты: если данные всё-таки попали в объект, pino заменит их на [Redacted]. Но полагаться только на redact ненадёжно — лучше не передавать персональные данные в логгер вообще.

При логировании платёжных операций — только идентификаторы, никаких данных карты:

// Плохо — payload может содержать данные карты
this.logger.info({ chargeRequest }, 'charge request');

// Хорошо — только orderId и сумма
this.logger.info({ orderId: chargeRequest.orderId, amount: chargeRequest.amount }, 'charge request');

Для ошибок всегда передавать объект ошибки через { err }, а не строку сообщения:

// Плохо — stack trace теряется
this.logger.error(`Failed to charge: ${err.message}`);

// Хорошо — pino разворачивает { err } в type, message, stack
this.logger.error({ err, orderId }, 'payment charge failed');

Коротко

• nestjs-pino — стандарт структурированного логирования в NestJS: JSON в продакшне, pino-pretty локально.
• console.log и new Logger() не дают контекста запроса — использовать @InjectPinoLogger.
• Данные передавать первым аргументом как объект, а не через шаблонную строку — это и быстрее, и удобнее для фильтрации.
• autoLogging: true пишет access-log автоматически — не дублировать info в каждом методе контроллера.
• AsyncLocalStorage в nestjs-pino обеспечивает requestId и trace_id в каждой записи без явной передачи.
• logger.assign({ userId }) в guard добавляет userId ко всем последующим логам запроса.
• Персональные данные — никогда в логах; redact как дополнительный рубеж, не основной.
• Ошибки через { err }, не err.message — иначе stack trace теряется.

Что почитать дальше

• Metrics — prom-client, RED/USE и стандартные labels
• Tracing — OTel NodeSDK и auto-instrumentations
• Health checks — terminus, liveness/readiness