首页 / 文章 / 诊断缓慢的 Node.js API：优化之前先测量延迟

Node.js Performance Observability Backend Debugging

诊断缓慢的 Node.js API：优化之前先测量延迟

学会将缓慢的 Node.js 请求拆解为事件循环延迟、连接池等待时间、查询耗时以及下游调用，从而找出真正耗费时间的环节并加以解决。

1841 词

一个请求的处理时间接近一秒，但CPU使用率仅约为容量的三分之一，内存使用情况也正常，数据库状态显示为绿色。即便对可能的问题进行优化，往往也收效甚微。本指南将逐阶段讲解请求的处理过程，帮助你找出时间消耗的所在，同时介绍一些能降低排查成本并提高结果可靠性的方法。

在指责运行时问题之前先测量请求时间

选择一条简单的路径，通过订单ID加载该订单并以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指标反映的是实际执行的工作量，而处于等待状态的请求几乎不消耗CPU资源。Node.js进程通常会等待以下内容：

获取数据库连接
查询执行本身
其他HTTP服务
网络I/O操作
消息队列
锁机制

CPU空闲但服务响应缓慢，通常意味着该服务并未处于繁忙状态，而是被阻塞了。

应关注事件循环延迟，而不仅仅是CPU百分比

Node.js 进程中的每个回调都共享同一个事件循环，因此定时器应触发的时间与实际触发时间之间的差值可直接反映系统的运行状况。node:perf_hooks 中的 monitorEventLoopDelay 会将该差值采样并生成直方图；此处采用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 如何导致事件循环阻塞。

当数据库成为罪魁祸首时

接下来，以相同方式对查询进行性能监控。

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

大多数连接池库都会提供空闲、总数和等待中的连接数；通过获取这些数据是最快捷的区分方法。

下游服务与顺序等待

许多接口会依次从多个依赖项中组装响应：

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

当某个数值令你惊讶时，应在采取行动之前将其拆解为各个组成部分。

避免使用高基数度的指标标签

用用户ID为延迟指标添加标签看似无害：

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

这种分工值得牢记：指标能提醒你有问题存在，而追踪信息则能显示问题出在何处。

遍历请求路径的检查清单

当延迟上升时，先不要急于增加服务器或CPU。追踪请求所经过的路径，并测量每一环节的延迟：

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值来评估延迟，而非仅依赖平均值。
保持指标的类别数量较少，对日志进行抽样处理且不得包含敏感信息，将每条请求的详细信息记录在追踪数据中。

需使用相同的百分位数以及可能受影响的邻近信号来验证每一项修复措施。

一旦能够观察到系统运行状况，慢速的系统也就容易处理了；在此之前，每一次改动都只是猜测。若想了解在确定瓶颈后应优先处理哪些修复措施，请参阅针对 Node.js API 性能的优先级排序优化框架。

全部文章发送简报