Представьте, endpoint на NestJS иногда отвечает за секунды вместо миллисекунд. Как вы будете искать причину?

Диагностика нестабильно медленного endpoint в NestJS

Периодические замедления (иногда миллисекунды, иногда секунды) — один из наиболее коварных сценариев. Причин может быть несколько: конкуренция за соединение с БД, GC-паузы, медленные внешние вызовы, блокирующий код в event loop. Ниже — последовательный план расследования.

Шаг 1: Сбор данных — добавить детальное измерение времени

import { Injectable, NestInterceptor, ExecutionContext, CallHandler, Logger } from '@nestjs/common';
import { Observable, tap } from 'rxjs';

@Injectable()
export class TimingInterceptor implements NestInterceptor {
  private readonly logger = new Logger('Timing');

  intercept(ctx: ExecutionContext, next: CallHandler): Observable<unknown> {
    const req = ctx.switchToHttp().getRequest();
    const start = process.hrtime.bigint();
    return next.handle().pipe(
      tap(() => {
        const ms = Number(process.hrtime.bigint() - start) / 1_000_000;
        this.logger.log(`${req.method} ${req.url} — ${ms.toFixed(2)}ms`);
      }),
    );
  }
}

Разбить endpoint на этапы: время до первого await, время ORM-запроса, время после. Это сразу покажет, какой этап «прыгает».

Шаг 2: Проверить пул соединений с БД

Самая частая причина intermittent slowness — ожидание свободного соединения в пуле.

// TypeORM DataSource
const dataSource = new DataSource({
  type: 'postgres',
  extra: {
    max: 20,          // размер пула
    idleTimeoutMillis: 30000,
    connectionTimeoutMillis: 2000, // если нет свободного — выбросить ошибку, а не ждать вечно
  },
});

Посмотреть в `pg_stat_activity`: сколько соединений в состоянии `active` и `idle in transaction`. Долгие транзакции удерживают соединение и блокируют остальные запросы.

Шаг 3: Проверить блокировку event loop

Синхронный CPU-интенсивный код (парсинг JSON, криптография, RegExp на больших строках) блокирует event loop и делает все запросы медленными одновременно. Выявить можно через `clinic.js`:

npx clinic doctor -- node dist/main.js
# Генерировать нагрузку параллельно:
npx autocannon -c 50 -d 30 http://localhost:3000/api/slow-endpoint

Если clinic показывает «Event Loop Blocked», искать синхронные операции в hot path. Решение: вынести в `worker_threads` или `child_process`.

Шаг 4: Проверить внешние HTTP-вызовы

• Добавить таймаут ко всем исходящим запросам: `axios.get(url, { timeout: 3000 })`.
• Проверить DNS-резолюцию: без кэша каждый запрос к внешнему сервису может занять 50–200 мс на резолвинг.
• Проверить keep-alive: по умолчанию axios не использует HTTP keep-alive, что приводит к TCP handshake на каждый запрос.

import { HttpModule } from '@nestjs/axios';
import * as http from 'http';
import * as https from 'https';

HttpModule.register({
  timeout: 5000,
  httpAgent: new http.Agent({ keepAlive: true }),
  httpsAgent: new https.Agent({ keepAlive: true }),
});

Шаг 5: GC-паузы и память

Node.js V8 major GC может останавливать event loop на 50–500 мс. Признак — периодические задержки без корреляции с нагрузкой на БД.

# Запустить с GC-логами:
node --expose-gc --trace-gc dist/main.js 2>&1 | grep -E "(Scavenge|Mark-sweep)"

Если есть частые major GC — искать утечки памяти или уменьшить размер кэшей в памяти.

Шаг 6: Трассировка через OpenTelemetry

// tracing.ts — запустить до импорта NestJS
import { NodeSDK } from '@opentelemetry/sdk-node';
import { JaegerExporter } from '@opentelemetry/exporter-jaeger';
import { getNodeAutoInstrumentations } from '@opentelemetry/auto-instrumentations-node';

const sdk = new NodeSDK({
  traceExporter: new JaegerExporter({ endpoint: 'http://jaeger:14268/api/traces' }),
  instrumentations: [getNodeAutoInstrumentations()],
});
sdk.start();

Jaeger UI покажет waterfall всех span-ов — сразу видно, какой внешний вызов или запрос к БД занял лишние секунды.

Подводные камни

• Intermittent slowness часто не воспроизводится в dev — тестировать под реалистичной конкурентной нагрузкой (autocannon, k6).
• N+1 запросы к БД проявляются только при реальных данных: 10 записей в dev, 10 000 в prod — разница в 3 порядка.
• Таймаут без circuit breaker: если внешний сервис начинает отвечать медленно, все потоки event loop блокируются в ожидании — добавить `@nestjs/throttler` или `opossum` circuit breaker.
• Long-running transaction без явного COMMIT/ROLLBACK удерживает соединение и блокирует пул.
• DNS кэш Node.js по умолчанию отсутствует — каждый `fetch`/`axios` запрос к внешнему API делает системный DNS lookup.
• REQUEST-scoped провайдеры под нагрузкой создают тысячи объектов — давление на GC нарастает постепенно и проявляется как intermittent slowness.
• Логирование в синхронном режиме (запись в файл без буфера) может блокировать event loop на высоком трафике — использовать `pino` с `transport`.
• `JSON.stringify` на больших объектах (ответ с тысячами записей) — блокирующая операция; для потоковой отдачи использовать `fast-json-stringify`.

• Сразу обвинять NestJS, не проверив соседние слои системы
• Чинить симптом без минимального воспроизведения и evidence
• Не учитывать версии, конфигурацию, окружение и recent changes

• Умеет локализовать проблему вокруг NestJS
• Двигается от симптома к гипотезам и проверкам
• Отличает баг инструмента от ошибки использования или окружения