从一次内存泄漏排查,看 Node 服务的日志与指标该怎么分工
线上服务第三天开始,RSS 从 180MB 一路涨到 620MB,但接口耗时和错误率都没有变化。这篇文章记录我怎么把日志与指标重新分工,并在两次发布内把增长曲线压平。
先把结论放在前面:日志回答“已经发生了什么”,指标回答“现在正在发生什么”。这两件事混在一起用,排查就会在时间线和现场之间来回跳,越查越乱。
01起点:曲线比错误更早报警
监控里最先是容器内存使用量的斜率变了:每过一小时涨 40MB 左右。CPU、QPS、P99 都在正常区间,错误日志一条没有。这个组合基本排除了请求量突增和下游抖动,问题更像是长期驻留的对象在累积。
bash
node --heapsnapshot-signal=SIGUSR2 server.js
kill -USR2 <pid>
ls -lh heap-*.heapsnapshot02日志能回答什么
- 单次请求的完整路径:哪个中间件先跑,谁调了外部服务
- 异常发生的上下文:入参、重试次数、上一次成功的时间
- 发布关联:某个版本上线后,同类日志是否突然变多
它回答不了“现在谁占着内存”。日志是离散事件,进程内的对象图不是事件。想要后者,必须在运行时暴露连续的量。
03指标能回答什么
| 指标 | 含义 | 我当时看到的 |
|---|---|---|
| process.memoryUsage().rss | 进程实际占用 | 线性上涨,无回落 |
| heapUsed | v8 堆内活跃对象 | 锯齿上涨,GC 后基线抬高 |
| activeHandles | 未释放的句柄数 | 每 6 小时增加 1 |
| eventLoopDelay P99 | 事件循环阻塞 | 稳定在 12ms |
activeHandles 这一行是转折点。堆快照里绝大多数对象都能被 GC 回收,说明泄漏不在业务数据,而在某个一直活着的句柄上。顺着这个方向,我找到了定时器注册的位置。
04改动的三处
第一处是订阅回调在实例销毁后没有解绑;第二处是重连逻辑每次都新建一个定时器,旧定时器只是被覆盖了引用;第三处是缓存没有上限,键里带时间戳,等于永不命中。
js
function attach(client, handler) {
client.on("message", (msg) => {
handler(msg);
});
}
attach(client, handle);js
function attach(client, handler) {
const listener = (msg) => handler(msg);
client.on("message", listener);
return () => client.off("message", listener);
}
const detach = attach(client, handle);
onDestroy(detach);第三处改成了带容量上限的 LRU,并且把时间戳从键里挪到值里。这一处对内存的影响比前两处都大,因为它决定了缓存到底有没有命中。
05复盘:分工写进规范
日志回答发生了什么,指标回答正在发生什么,链路追踪回答影响了谁。
- 请求级别的事实写进日志,必须带 trace id 和稳定的字段名
- 进程与资源级别的量做成指标,暴露在固定路径,采样间隔小于 15 秒
- 跨服务的影响交给追踪,不在日志里手写耗时
这套分工执行两周后,同类问题第一次报警的同时就能看到增长的是哪个量,排查时间从半天压到半小时以内。更重要的是,修复之后不会再靠感觉判断有没有效。