Logging — pino JSON, AsyncLocalStorage, уровни и PII-гигиена (NestJS)

nestjs-pino: JSON в проде, pino-pretty локально, DI-логгер @InjectPinoLogger, merge-объект вместо конкатенации, redact для PII, trace_id через AsyncLocalStorage. Правила R-OBS-LOG.

Опубликовано 19 июня 2026 ~7 мин чтения Автор: Вадим Викулин

Опирается на правила: R-OBS-LOG-1 … R-OBS-LOG-6 и R-OBS-LOG-X1 … R-OBS-LOG-X6 из Observability Style Guide → раздел 1. Logging.

Важно знать

JSON в проде через nestjs-pino (pino stdout as-is); pino-pretty transport только при NODE_ENV=development. JSON парсится Loki/ELK/Datadog без regex.

DI-логгер через @InjectPinoLogger — никаких new Logger() и console.log.

Merge-объект первым аргументом — структурные поля ({ orderId, customerId }), не template-literal конкатенация.

Уровни осмысленные: error — actionable + { err } со stack, warn — деградация/retry/CB, info — бизнес-события, debug — только не в проде.

trace_id/span_id (OTel auto), requestId (из X-Request-Id или UUID), userId (после JWT) — в каждой записи через request-scoped logger (AsyncLocalStorage, nestjs-pino).

PII в логах запрещены (AUTH-16): email, phone, ФИО, токены, пароли. Закрывать через redact config или не логировать.

{ err } для ошибок — pino-сериализатор выводит stack; logger.error(err.message) stack теряет.

Логи — основной инструмент восстановления картины инцидента. Если они не structured, не содержат trace_id, размазаны console.log по кодовой базе — расследование превращается в часы grep по миллиону строк. UCP-правила для Node закрывают это через nestjs-pino: каждый log-entry несёт контекст запроса с рождения.

JSON в проде, pino-pretty в dev

R-OBS-LOG-1: конфигурация nestjs-pino переключается по NODE_ENV.

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

@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 {}

В dev — форматированная строка с цветом для глаз. В проде — JSON одной строкой с полями time, level, msg, req.id, trace_id, span_id, userId. Loki/ELK индексируют поля и дают фильтры без regex.

redact убирает чувствительные поля из лога автоматически. Удалять поле из объекта руками до передачи в логгер — хрупко и забывается; redact — контракт, прописанный один раз.

DI-логгер через @InjectPinoLogger

R-OBS-LOG-2: логгер инжектируется через DI, привязан к имени класса. Никаких new Logger() и console.

// 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) передаёт name (имя класса) в пространство имён логгера — поле context в каждой записи. При рефакторинге класса имя обновляется автоматически.

Merge-объект вместо конкатенации

R-OBS-LOG-3: структурные поля передаются первым аргументом как объект, сообщение — строкой.

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

// AVOID — template literal конкатенация
this.logger.info(`Order created: ${JSON.stringify(order)}`);
// JSON.stringify выполняется ВСЕГДА, даже если уровень disabled

Почему template-literal опасен: JSON.stringify(order) выполняется при каждом вызове, даже если уровень debug выключен в проде. На горячем пути (orders, payments) — заметная нагрузка на CPU.

Pino сам сериализует объекты при активном уровне. Merge-объект попадает в JSON-поля верхнего уровня — Loki может фильтровать { orderId="..." } напрямую.

Уровни логов

R-OBS-LOG-4: семантика каждого уровня.

Уровень	Когда
`error`	Actionable failure: незакрытое исключение, упавшая транзакция, недоступность внешнего ресурса. Всегда с `{ err }`.
`warn`	Recoverable degradation: Circuit Breaker открылся, retry attempt, fallback использован.
`info`	Important business event: «order confirmed», «payment received», start/stop приложения, batch start/end с count.
`debug`	Детали для отладки. В проде выключено, включается per-module при инциденте.
`trace`	Сверх-детально. Прод никогда.

// PaymentService
this.logger.error({ err, orderId }, 'payment charge failed');
this.logger.warn({ orderId, attempt }, 'payment provider retry');
this.logger.info({ orderId, amount: order.amount, customerId }, 'order confirmed');
this.logger.debug({ orderState: order }, 'aggregate state after confirm');

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

Контекстные поля в каждой записи

R-OBS-LOG-5: nestjs-pino через AsyncLocalStorage делает request-scoped logger — каждая запись в рамках HTTP-запроса автоматически несёт:

req.id (requestId) — из X-Request-Id header или сгенерированный UUID (genReqId).
trace_id / span_id — автоматически через @opentelemetry/instrumentation-pino.
userId — добавляется после JWT-валидации в guard/interceptor.

// auth.guard.ts — обогащение после JWT
@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",
  "span_id": "1f2e3d4c5b6a7980",
  "userId": "user-42",
  "orderId": "order-789",
  "amount": 4990
}

Логи на границах

R-OBS-LOG-6: логируем там, где сервис общается с внешним миром.

Inbound REST — autoLogging: true в nestjs-pino пишет access-log на каждый запрос. INFO внутри handler-а — только для критичных команд (платежи).

// order.controller.ts — платёжная команда
@Post(':id/confirm')
async confirmOrder(@Param('id') orderId: string): Promise<void> {
  this.logger.info({ orderId }, 'confirm order request received');
  await this.confirmOrderUseCase.execute({ orderId });
}

Outbound HTTP (через axios / got): INFO на вызов, WARN на 4xx, ERROR на сетевую ошибку.

// payment.client.ts
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;
  }
}

Domain events — INFO на publish: { eventType: 'OrderConfirmed', orderId }.

Schedulers / BullMQ processors — INFO на start/end batch с count.

// outbox.processor.ts
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');
}

В середине бизнес-логики логи только когда что-то решено или произошёл warn. Не «Entering method», не «Loaded N rows» — это шум.

Что запрещено

PII в логах

R-OBS-LOG-X1 — критическое нарушение, AUTH-16. Email, телефон, ФИО, адрес, паспорт, токены, пароли — никогда в логах в открытом виде.

// ПЛОХО — PII в логах
this.logger.info(
  { email: user.email, phone: user.phone },
  'customer registered',
);

// ХОРОШО — только internal id
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 в nestjs-pino — второй рубеж: автоматически скрывает поля по path (*.email, req.headers.authorization). Но redact не замена — не логировать PII вообще надёжнее.

`console.log` и `console.error`

R-OBS-LOG-X2: пишут в stdout без контекста запроса, без уровня, без trace_id. Не попадают в structured pipeline.

// ПЛОХО
console.log('Order confirmed:', order);
console.error(err);

// ХОРОШО
this.logger.info({ orderId: order.id }, 'order confirmed');
this.logger.error({ err }, 'unexpected error');

В NestJS-проектах console блокируется eslint-правилом no-console. Любое появление на ревью — возврат.

Тяжёлая сериализация в аргументе

R-OBS-LOG-X3: JSON.stringify внутри строки лога выполняется всегда.

// ПЛОХО — сериализация всегда, даже на debug-уровне в проде
this.logger.debug(`Product full state: ${JSON.stringify(product)}`);

// ХОРОШО — pino сериализует только при активном уровне
this.logger.debug({ product }, 'product state');

`logger.error` без err-объекта

R-OBS-LOG-X4: logger.error(err.message) теряет stack trace.

// ПЛОХО — stack теряется
this.logger.error(`Failed to charge: ${err.message}`);

// ХОРОШО — pino-сериализатор разворачивает { err } в stack_trace
this.logger.error({ err, orderId }, 'payment charge failed');

Pino распознаёт поле err и через встроенный serializer выводит type, message, stack. JSON получает поле err.stack — можно фильтровать в Loki по stack.

Полный request body для money/PII-эндпоинтов

R-OBS-LOG-X5: при обработке платежей и персональных данных логировать только идентификаторы.

// ПЛОХО — payload может содержать card details / PII
this.logger.info({ chargeRequest }, 'charge request');

// ХОРОШО — только orderId и amount
this.logger.info({ orderId: chargeRequest.orderId, amount: chargeRequest.amount }, 'charge request');

INFO в каждом handler-е на HTTP-запрос

R-OBS-LOG-X6: autoLogging: true в nestjs-pino пишет access-log за тебя. Дублировать INFO в каждом controller method — шум. Исключение — критичные команды с бизнес-значением (подтверждение заказа, платёж).

Что запрещено — таблица

Антипаттерн	Правило	Что взамен
PII в логах (email, phone, ФИО, токены)	`R-OBS-LOG-X1`	маскировать или только internal id; `redact` config
`console.log` / `console.error`	`R-OBS-LOG-X2`	`@InjectPinoLogger` + `logger.info/error`
Template-literal с `JSON.stringify` в аргументе	`R-OBS-LOG-X3`	merge-объект первым аргументом
`logger.error(err.message)` без `{ err }`	`R-OBS-LOG-X4`	`logger.error({ err, orderId }, 'failed')`
Полный request body для money/PII	`R-OBS-LOG-X5`	только `orderId` + `amount`
INFO на каждый HTTP-запрос в handler	`R-OBS-LOG-X6`	`autoLogging: true` в nestjs-pino
`pino-pretty` в проде (не JSON)	`R-OBS-LOG-1`	`transport` только при `NODE_ENV !== 'production'`
`new Logger()` / `console` вместо DI	`R-OBS-LOG-2`	`@InjectPinoLogger(ClassName.name)`
Логи без `trace_id` / `requestId`	`R-OBS-LOG-5`	request-scoped logger через nestjs-pino ALS

Куда дальше

Context propagation — как requestId, trace_id, userId живут в AsyncLocalStorage и пробрасываются в BullMQ.
Конфигурация — nestjs-pino setup, management-порт, профили.
Metrics — prom-client, RED-histogram, default labels.
Tracing — OTel NodeSDK, auto-instrumentations, manual span.
Health checks — terminus, liveness/readiness, custom HealthIndicator.
SLO и алерты — error budget, multi-window alerts, runbook.