Node 内存泄漏排查案例

背景

在阿里云上看到我运行了一段时间的程序，发现 memory 一项基本是在稳步提升，就知道有内存泄漏的情况出现。如下图

Node 内存泄漏排查案例-LMLPHP

近三日从 35% 升到 40%，缓慢而坚定的提升。

代码

排查此问题需要分析其堆内存快照，当然我们不能直接使用线上机器调试。不幸的是测服机器在内网，和阿里云联不通，alinode 发挥不了作用。但所幸的是 V8 引擎提供了内部接口可以直接把堆中的JS对象导出来供开发者分析。我们采用heapdump这个模块，执行如下命令安装

$ npm install heapdump --save

"heapdump": "^0.3.15",

执行如下

const heapdump = require('heapdump');
heapdump.writeSnapshot(`./${Date.now()}.heapsnapshot`);

生成的文件如下

$ ll -lh

-rw-rw-r-- 1 souche souche  38M Nov 19 19:00 1574161221512.heapsnapshot

总之我在测服上定时每 2 小时打印堆栈快照。

总之，你可以使用 scp 命令把测服的代码导出到本地

# 传递单个文件

$ scp 【服务器用户名】@【服务器地址】：【服务器上存放文件的路径】【本地文件的路径】

# 例如

$ scp [email protected]:/home/souche/app/egg-test/current/1574161221512.heapsnapshot /Users/dasouche/workspace/sc-node

# 传递文件夹

scp -r 【服务器用户名】@【服务器地址】：【服务器上存放文件的路径】【本地文件的路径】

分析步骤

打开 chrome-控制台-Memory-load

Node 内存泄漏排查案例-LMLPHP

加载完后得到

Node 内存泄漏排查案例-LMLPHP

简而言之，Shallow Size 就是对象自身被创建时所需要内存的大小，Retained Size 就是当把对象从支配树上拿掉，对象和它的下级节点一共能释放的内存大小。

其术语简介可参见：https://developers.google.com/web/tools/chrome-devtools/memory-problems/memory-101

分析过程

从线上机器导出两个堆文件，一个是10月30日打印的，一个是11月4日打印的，其内存上升了 100+ MB。

比对两个堆，把第二个堆文件的 Summary 切换成 Comparison，并按 Delta 倒叙排，发现增长最快的是 (concatenated string) 。其中有很多连接字符串，其中有大量的sql语句，并且有大量的schedule执行。

Node 内存泄漏排查案例-LMLPHP

(constructor) 增长排第二，其中也见到不少 schedule，那我们可以确认就是 noticeJob.ts 这个定时器的问题。

Node 内存泄漏排查案例-LMLPHP

本项目使用了 egg 作为框架，schedule 就是指定时触发的逻辑。联系代码我们发现在一个 5 秒触发一次的 schedule 里，里面不停的触发队列的 process 监听事件，猜测是 Queue.process 监听事件越绑越多的毛病，也导致里面的逻辑越触发越多。

这其实就是队列绑定监听事件的误用了。

// app/schedule/noticeJob.ts
'use strict';

import { Context } from 'egg';
import * as kue from 'kue';

module.exports = {
  schedule: {
    disable: false,
    // 每五秒触发一次
    cron: '*/5 * * * * *',
    immediate: true,
    type: 'worker',
  },

  async task(ctx: Context) {
    const Queue = ctx.app.kue;

    Queue.process('noticeCalling', async function(job, done) {
      const { uid, rid, subId } = job.data;
      await ctx.service.message.noticedCalling(uid, rid);
      // done();
    });
  },
};

我们在测服注释掉这段定时器后，每隔一小时打印一次（因为测服无法连阿里云），观察一天，内存没有上升趋势，这很好。

-rw-rw-r--  1 souche souche  38M Nov 24 11:24 1574565877609.heapsnapshot
-rw-rw-r--  1 souche souche  37M Nov 24 12:24 1574569477611.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 13:24 1574573077611.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 14:24 1574576677613.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 15:24 1574580277614.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 16:24 1574583877614.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 17:24 1574587477616.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 18:24 1574591077616.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 19:24 1574594677616.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 20:24 1574598277618.heapsnapshot
-rw-rw-r--  1 souche souche  37M Nov 24 21:24 1574601877620.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 22:24 1574605477621.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 24 23:24 1574609077622.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 00:24 1574612677622.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 01:24 1574616277622.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 02:24 1574619877623.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 03:24 1574623477624.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 04:24 1574627077626.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 05:24 1574630677627.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 06:24 1574634277627.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 07:24 1574637877628.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 08:24 1574641477629.heapsnapshot
-rw-rw-r--  1 souche souche  38M Nov 25 09:24 1574645077630.heapsnapshot
-rw-rw-r--  1 souche souche  39M Nov 25 10:24 1574648677630.heapsnapshot
-rw-rw-r--  1 souche souche  39M Nov 25 11:24 1574652277632.heapsnapshot

解决方法

最后就在 app.ts 设置这个 process 的监听，移除 schedule 里的定时脚本

Ever-Lose