Діагностика повільних API Node.js: вимірюйте затримку перед оптимізацією

Обробка запиту займає майже секунду, проте потужність CPU використовується лише приблизно на третину, оперативна пам’ять не викликає особливих зауважень, а панель керування базою даних має зелений статус. Налаштування того, що ви підозрюєте, рідко допомагає. Цей посібник пояснює кожен етап обробки запиту, щоб ви могли з’ясувати, де йде час, а також наводить практики використання інструментів, які дозволяють ефективно та надійно проводити дослідження.

Виміряйте час обробки запиту, перш ніж звинувачувати середовище виконання

Використайте простий шлях, який завантажує замовлення за його ідентифікатором та повертає його у форматі JSON.

app.get("/orders/:id", async (req, res) => {
  const order = await getOrder(req.params.id);
  res.json(order);
});

Припустимо, час відповіді становить приблизно 900 мс. Замість того, щоб звинувачувати Node.js, обгорніть операцію очікування виклику функцією performance.now(), щоб побачити, яку частину загального часу вона займає.

const start = performance.now();

const order = await getOrder(req.params.id);
console.log(
  `getOrder: ${performance.now() - start}ms`
);
res.json(order);

Числа зазвичай швидко вирішують питання:

Request:       910ms
getOrder():    870ms
Node.js:        40ms

Майже вся затримка виникає під час виконання функції getOrder(); супутні операції JavaScript займають близько 40 мс. Цей час витрачається на очікування чогось у нижчих рівнях ієрархії.

Низький рівень використання CPU не означає належної роботи сервісу

Панель контролю використання ресурсів, подібна до наведеної нижче, здається обнадійливою:

CPU: 32%
Memory: 48%

Показник CPU відображає обсяг виконуваних операцій, а запити, які очікують на обробку, майже не споживають ресурсів. Типові причини очікування процесу Node.js:

• отримання підключення до бази даних
• сам запит
• інший HTTP-сервіс
• загальні мережеві операції вводу-виводу
• очередь повідомлень
• блокування

Повільний сервіс із неактивним CPU зазвичай не працює у повну силу; він заблокований.

Слідкуйте за затримкою циклу подій, а не лише за відсотком використання CPU

Кожен калебек у процесі Node.js користується одним циклом подій, тому різниця між моментом, коли має спрацювати таймер, та моментом його реальної дії, є прямим показником стану системи. Функція monitorEventLoopDelay з модуля node:perf_hooks вимірює цю різницю та формує з неї гістограму; у цьому прикладі використовується роздільна здатність 20 мс, а значення p95 та p99 виводяться кожні п’ять секунд.

import { monitorEventLoopDelay } from "node:perf_hooks";

const histogram = monitorEventLoopDelay({
  resolution: 20
});
histogram.enable();
setInterval(() => {
  console.log({
    p95: histogram.percentile(95),
    p99: histogram.percentile(99)
  });
}, 5000);

Якщо результат виглядає так, цикл працює нормально та не може пояснити затримку запиту у 900 мс:

p95 event-loop delay: 8ms
p99 event-loop delay: 14ms

Цифри у розмірі сотень мілісекунд розповідають зовсім іншу історію:

p95: 180ms
p99: 650ms

Зараз щось монополізує цикл. Типовою причиною є синхронна функція з високою навантаженням на CPU, яка викликається безпосередньо всередині обробника:

app.get("/report", (req, res) => {
  const result = expensiveCalculation();
  res.json(result);
});

Поки виконується expensiveCalculation(), жоден інший запит у цьому процесі не просувається далі. На многопроцесорному сервері загальна карта використання CPU все одно може виглядати помірною, оскільки один перевантажений ядро усереднюється з неактивними, тому затримка циклу часто є більш точною міркою, ніж відсоток використання CPU. Звичайним рішенням є переміщення такої роботи у поток-робітника, чергу завдань або окремий сервіс. Схожа ситуація, коли саме планування мікрозавдань, а не обчислення, призводить до затримки циклу, розглядається у статті про те, як process.nextTick може призводити до затримки циклу подій у Node.js.

Коли вина лежить на базі даних

Далі інструментуйте запит таким самим способом.

const start = performance.now();
const result = await db.query(
  "SELECT * FROM orders WHERE customer_id = $1",
  [customerId]
);
console.log(
  `DB query: ${performance.now() - start}ms`
);

Тепер причина проблеми безумовно лежить у базі даних:

Total request: 850ms
Node.js:        15ms
DB query:      810ms
Serialization:  25ms

Перш ніж переписувати SQL, перевірте, чи була запитувана операція повільною, або чи очікував запит на з’єднання.

Виснаження пулу, що імітує повільний запит

Розгляньмо пул ресурсів такого розміру:

API instances:        10
Connections/instance: 20

Total connections:   200

Потім надходить сплеск трафіку:

Requests:          500
Active DB queries:  20
Waiting requests: 480

Кожен екземпляр може виконувати лише 20 запитів, тому решта потрапляє у чергу всередині пулу. Один запит може зайняти 30 мс, але запит у кінці черги чекає сотні мілісекунд, перш ніж дістатися до бази даних. Таймер додатку повідомляє:

DB call = 500ms

Сама база даних повідомляє:

Query = 30ms

Повільний запит вимагає індексів або кращого плану виконання; тривала затримка вимагає збільшення розміру пулу, скорочення тривалості транзакцій або зменшення кількості обмінів даними. Вимірюйте окремо кожен етап, а не лише загальну „затримку бази даних“:

Connection wait
      +
Query execution
      +
Result processing

Більшість бібліотек пулів відображають кількість вільних, загальну та очікуючих елементів; їх експорт — це найшвидший спосіб розрізнити ці випадки.

Служби нижчого рівня та послідовні операції await

Багато кінцевих точок формують відповідь з кількох залежностей по черзі:

const customer = await customerService.get(id);

const payment = await paymentApi.get(
  customer.paymentId
);
const orders = await orderService.get(id);

Вимірювання часу кожного виклику окремо дозволяє виявити аномалії:

Customer API:    40ms
Payment API:    700ms  ← 🚨
Orders DB:       35ms
Node.js:         15ms

Служба оплати домінує, і оскільки кожна операція await чекає на попередню, затримки накопичуються:

40ms + 700ms + 35ms + 15ms
≈ 790ms

Незалежні виклики можуть початися одночасно. Для пошуку клієнта та замовлення потрібен лише id, тому Promise.all об’єднує їх:

const [customer, orders] = await Promise.all([
  customerService.get(id),
  orderService.get(id)
]);

Виклик для оплати все ще чекає, оскільки йому потрібен customer.paymentId. Не паралелізуйте автоматично: додаткова конкурентність підвищує навантаження на пули, API та пам’ять, а за високого навантаження може погіршити ситуацію.

Перцентили показують те, що приховують середні значення

Панель керування, яка відображає цю інформацію, здається прийнятною:

Average latency: 120ms

Перцентильний погляд на той самий трафік менш заспокійливий:

p50:  80ms
p95: 180ms
p99: 2.8s

Середнє значення описує звичайний запит; крайні значення — користувачів, які стикаються з перевантаженим ресурсом чи повільною залежністю. Відстежуйте розподіл:

p50
p95
p99

Інструменти, які допомагають, а не шкодять

Вимірювання потребують ресурсів CPU, зберігання та уваги. Кілька правил допоможуть зберегти їх корисність.

Вимірюйте на межах, а не в кожному допоміжному функції

Вимірювання кожної функції таким чином створює більше шуму, ніж корисної інформації:

const start = performance.now();
// ...
console.log(performance.now() - start);

Вимірюйте там, де запит переходить до іншої системи, адже саме там відбувається очікування:

HTTP request
   ↓
Database
   ↓
External API
   ↓
Queue
   ↓
Response

Контролюйте журналування за кожним запитом

Журнальний запис за кожним запитом стає дорогим при високій пропускній здатності:

console.log({
  path: req.path,
  duration,
  userId: req.user.id
});

Використовуйте структуроване логування з рівнями та вибіркою, і повністю уникайте включення цього до логів:

passwords
tokens
authorization headers
payment information

Тривалість — це не діагноз

Наявність такої цифри не доводить, що SQL-запит виконувався саме стільки часу:

DB: 700ms

Цей проміжок часу може включати кілька різних факторів, що впливають на тривалість:

Connection acquisition
+
Query execution
+
Network
+
Result transfer
+
Client-side processing

Якщо число вас здивувало, розберіть його на складові перед тим, як приймати рішення щодо нього.

Уникайте метрик із високою кардинальністю

Позначення метрики затримки ідентифікатором користувача здається безневинним:

http_request_duration{user_id="123456"}

При мільйонах користувачів це означає мільйони тайм-серій. Краще використовувати обмежені розміри:

route
method
status_code
service

Добре позначена тайм-серія виглядає ось так:

http_request_duration{
  route="/orders/:id",
  method="GET",
  status="200"
}

Деталі за кожним запитом мають знаходитися у логах та трекінг-даних.

Свідомо використовуйте вибірку

Звичайна політика відстежує частину звичайного трафіку та все цікаве:

Normal traffic → sample a percentage
Errors         → capture aggressively
Slow requests  → capture aggressively

Співвідношення залежить від трафіку, інструментарію та бюджету; метою є наявність достатньо доказів для пояснення несправностей, а не їх повна відстежуваність.

Порівняйте до та після, за кількома показниками

Фраза «Здається, швидше» не є доказом. Запишіть процентиль до змін:

Before:
p95 = 820ms

І знову після неї:

After:
p95 = 410ms

Потім переконайтеся, що ніщо інше не змістилося у неправильному напрямку:

error rate
CPU
memory
DB load
connection pool usage

Швидший запит, який подвоює використання пулу чи навантаження на базу даних, просто переміщує проблему.

Відстежуйте окремий запит за допомогою трекінгу

Показник на рівні маршруту повідомляє лише загальну кількість:

GET /orders = 980ms

Розподілений трек розділяє один і той самий запит на окремі етапи, тож вартість кожної стадії видна одразу:

GET /orders
│
├── Node.js processing       15ms
├── DB connection wait      120ms
├── PostgreSQL query         40ms
├── Payment API             700ms
├── JSON serialization       20ms
└── Network                   5ms
                              ───
                              900ms

Цей розподіл обов’язків варто пам’ятати: метрики попереджають вас про те, що щось не так, а трекінг показує, де саме виникає проблема.

Чек-лист для аналізу шляху запиту

Коли зростає затримка, утримуйтеся від негайного додавання серверів чи процесорів. Простежте шлях, який проймає запит, та виміряйте кожен етап:

Request
   ↓
Queue / Load Balancer
   ↓
Node.js
   ↓
Event Loop
   ↓
Connection Pool
   ↓
Database
   ↓
External APIs
   ↓
Network
   ↓
Response

На кожному етапі поставте конкретне запитання:

Is the event loop blocked?

Are requests waiting for connections?

Are database queries slow?

Are downstream APIs slow?

Are we waiting on network I/O?

Is the queue growing?

Is garbage collection causing pauses?

Is the response itself expensive to serialize?

Кожне з цих запитань можна відповісти за допомогою даних, тому немає потреби здогадуватися.

Що зазвичай показують докази

Повернімося до початкової ситуації:

API latency: 900ms
CPU: 35%
Memory: 48%

Після вимірювання кожного етапу картина стає зовсім іншою:

Event loop:          12ms
DB query:            35ms
Connection wait:    120ms
Payment API:        700ms
Serialization:       20ms
Network:              5ms

Без переписування коду під час виконання допоможе більший об’єм пам’яті чи інстанція. Основними проблемами є затримка 700 мс, пов’язана з оплатою (кешування, таймаут із резервним варіантом чи переміщення цього процесу за межі шляху запиту), та затримка 120 мс на підключення (розмір пулу чи обсяг запитів).

Ключові висновки

Інстинктивний підхід виглядає так:

Slow API
   ↓
Add more servers

Ефективний підхід виглядає так:

Slow API
   ↓
Measure
   ↓
Break down latency
   ↓
Find the bottleneck
   ↓
Fix the bottleneck
   ↓
Measure again

• Спочатку виміряйте час виконання всього запиту, а потім розділіть його на частини на кожному етапі, де він залишає процес.
• Вважайте затримку циклу подій основним показником стану Node.js; відсоток використання CPU може приховувати проблему з одним заблокованим ядром.
• Розділіть час очікування на підключення від виконання запиту ще до роботи з SQL.
• Оцінюйте затримку за показниками p95 та p99, а не середніми значеннями.
• Зберігайте метрики з низькою кардинальністю, логи мають бути вибірковими та не містити конфіденційної інформації, а деталі кожного запиту — у треках.

Перевіряйте кожне виправлення за допомогою тих самих перцентилів та сусідніх сигналів, які воно могло вплинути.

Повільну систему можна керувати, як тільки вона стає видимою; до цього моменту кожна зміна є припущенням. Щоб дізнатися, які виправлення слід пріоритезувати після виявлення «вузького місця», перегляньте фреймворк з пріоритетним порядком для оптимізації продуктивності API Node.js.