转自:http://blog.eood.cn/node-js_gc
最近做的服务器端组件大部分都在使用 Node.js 。因为 Node.js 库管理模式比较先进,并且依托于 Github 的流行,Node.js 开源的库非常多,一般所需要的第三方库都可以找到。虽然这些库有很多明显的 Bug 但是比从零自己开发要快很多。对于服务器端开发,Node.js 还是个不错的选择,不像 Erlang 更接近底层,业务层面的库相对要少很多。
最近写的一个功能在本地开发的时候没有明显问题,但是到真实环境测试的时候发现内存不断增长,并且增长很快,同时 CPU 占用也很高,接近单核心的 100% 。这对于一个大部分都是 IO 操作的进程显然是有问题的。所以尝试分析内存和 CPU 异常的原因。最终发现是因为生产者和消费者速度差异引起的缓冲区暴增。在 MySQL 连接对象的 Queue 中积压了大量的 Query,而不是内存泄漏。
查看 Node.js 进程的 GC log:
node --trace_gc --trace_gc_verbose test.js
61 ms: Scavenge 2.2 (36.0) -> 1.9 (37.0) MB, 1 ms [Runtime::PerformGC].
Memory allocator, used: 38780928, available: 1496334336
New space, used: 257976, available: 790600
Old pointers, used: 1556224, available: 0, waste: 0
Old data space, used: 1223776, available: 4768, waste: 0
Code space, used: 1019904, available: 0, waste: 0
Map space, used: 131072, available: 0, waste: 0
Cell space, used: 98304, available: 0, waste: 0
Large object space, used: 0, available: 1495269120
97 ms: Mark-sweep 11.7 (46.1) -> 5.4 (40.7) MB, 10 ms [Runtime::PerformGC] [GC in old space requested].
Memory allocator, used: 42717184, available: 1492398080
New space, used: 0, available: 1048576
Old pointers, used: 1390648, available: 165576, waste: 0
Old data space, used: 1225920, available: 2624, waste: 0
Code space, used: 518432, available: 501472, waste: 0
Map space, used: 60144, available: 70928, waste: 0
Cell space, used: 23840, available: 74464, waste: 0
Large object space, used: 3935872, available: 1491332864
关于 Node.js 的 GC
Node.js 的 GC 方式为分代 GC (Generational GC)。对象的生命周期由它的大小决定。对象首先进入占用空间很少的 new space (8MB)。大部分对象会很快失效,会频繁而且快速执行 Young GC (scavenging)*直接*回收这些少量内存。假如有些对象在一段时间内不能被回收,则进入 old space (64-128KB chunks of 8KB pages)。这个区域则执行不频繁的 Old GC/Full GC (mark-sweep, compact or not),并且耗时比较长。(Node.js 的 GC 有两类:Young GC: 频繁的小量的回收;Old GC: 长时间存在的数据)
Node.js 最新增量 GC 方式虽然不能降低总的 GC 时间,但是避免了过大的停顿,一般大停顿也限制在了几十 ms 。
为了减少 Full GC 的停顿,可以限制 new space 的大小
--max-new-space-size=1024 (单位为 KB)
手动在代码中操作 GC (不推荐)
node --expose-gc test.js
修改 Node.js 默认 heap 大小
node --max-old-space-size=2048 test.js (单位为 MB)
Dump 出 heap 的内容到 Chrome 分析:
安装库
https://github.com/bnoordhuis/node-heapdump
在应用的开始位置添加
var heapdump = require('heapdump');
在进程运行一小段时间后执行:
kill -USR2 <pid>
这时候就会在当前目录下生成 heapdump-xxxxxxx.heapsnapshoot 文件。
将这个文件 Down 下来,打开 Chrome 开发者工具中的 Profiles,将这个文件加载进去,就可以看到当前 Node.js heap 中的内容了。
可以看到有很多 MySQL 的 Query 堆积在处理队列中。内存暴涨的原因应该是 MySQL 的处理速度过慢,而 Query 产生速度过快。
所以解决方式很简单,降低 Query 的产生速度。内存暴涨还会引起 GC 持续执行,占用了大量 CPU 资源。
node-mysql 库中的相关代码,其实应该限制 _queue 的 size,size 过大则抛出异常或者阻塞,就不会将错误扩大。
Protocol.prototype._enqueue = function(sequence) {
if (!this._validateEnqueue(sequence)) {
return sequence;
}
this._queue.push(sequence);
var self = this;
sequence
.on('error', function(err) {
self._delegateError(err, sequence);
})
.on('packet', function(packet) {
self._emitPacket(packet);
})
.on('end', function() {
self._dequeue();
});
if (this._queue.length === 1) {
this._parser.resetPacketNumber();
sequence.start();
}
return sequence;
};
在不修改 node-mysql 的情况下,加入生产者和消费者的同步,调整之后,内存不再增长,一直保持在不到 100M 左右,CPU 也降低到 10% 左右。
Node.js 调试工具 node-inspector
安装:
npm install -g node-inspector
启动自己的程序:
node --debug test.js
node --debug-brk test.js (在代码第一行加断点)
启动调试器界面:
node-inspector
打开 http://localhost:8080/debug?port=5858 可以看到执行到第一行的断点。
右边为局部变量和全局变量、调用栈和常见的断点调试按钮,查看程序步进执行情况。并且你可以修改正在执行的代码,比如在关键的位置增加 console.log 打印信息。
Node.js 命令行调试工具
以 DEBUG 模式启动 Node.js 程序,类似于 GDB:
node debug test.js
debug> help
Commands: run (r), cont (c), next (n), step (s), out (o), backtrace (bt), setBreakpoint (sb), clearBreakpoint (cb),
watch, unwatch, watchers, repl, restart, kill, list, scripts, breakOnException, breakpoints, version
Node.js 其他常用命令参数
node --max-stack-size 设置栈大小
node --v8-options 打印 V8 相关命令
node --trace-opt test.js
node --trace-bailout test.js 查找不能被优化的函数,重写
node --trace-deopt test.js 查找不能优化的函数
Node.js 的 Profiling
V8 自带的 prof 功能:
npm install profiler
node --prof test.js
会在当前文件夹下生成 v8.log
安装 v8.log 转换工具
sudo npm install tick -g
在当前目录下执行
node-tick-processor v8.log
可以关注其中 Javascript 各个函数的消耗和 GC 部分
[JavaScript]:
ticks total nonlib name
67 18.7% 20.1% LazyCompile: *makeF /opt/data/app/test/test.js:6
62 17.3% 18.6% Function: ~ /opt/data/app/test/test.js:9
42 11.7% 12.6% Stub: FastNewClosureStub
38 10.6% 11.4% LazyCompile: * /opt/data/app/test/test.js:1
[GC]:
ticks total nonlib name
27 7.5%
参考以及一些有用的链接