Node.js 調試 GC 以及內存暴漲的分析

Node.js 調試 GC 以及內存暴漲的分析

Posted Mar.26, 2013 under JavaScript, Web 開發 by Bruce Dou

最近做的伺服器端組件大部分都在使用 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

關於 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.jsnode --debug-brk test.js (在代碼第一行加斷點)

啟動調試器界面：

node-inspector

打開 http://localhost:8080/debug?port=5858 可以看到執行到第一行的斷點。
右邊為局部變量和全局變量、調用棧和常見的斷點調試按鈕，查看程序步進執行情況。並且你可以修改正在執行的代碼，比如在關鍵的位置增加 console.log 列印信息。

Node.js 命令行調試工具

以 DEBUG 模式啟動 Node.js 程序，類似於 GDB：

node debug test.jsdebug> helpCommands: 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.jsnode --trace-bailout test.js 查找不能被優化的函數，重寫node --trace-deopt test.js 查找不能優化的函數

Node.js 的 Profiling

V8 自帶的 prof 功能：

npm install profilernode --prof test.js

會在當前文件夾下生成 v8.log

安裝 v8.log 轉換工具

sudo npm install tick -g

在當前目錄下執行

node-tick-processor v8.log

可以關注其中 Javascript 各個函數的消耗和 GC 部分

[JavaScript]:ticks total nonlib name67 18.7% 20.1% LazyCompile: *makeF /opt/data/app/test/test.js:662 17.3% 18.6% Function: ~ /opt/data/app/test/test.js:942 11.7% 12.6% Stub: FastNewClosureStub38 10.6% 11.4% LazyCompile: * /opt/data/app/test/test.js:1[GC]:ticks total nonlib name27 7.5%

參考以及一些有用的連結

https://bugzilla.mozilla.org/show_bug.cgi?id=634503

http://cs.au.dk/~jmi/VM/GC.pdf
http://lifecs.likai.org/2010/02/how-generational-garbage-collector.html
http://en.wikipedia.org/wiki/Garbage_collection_(computer_science)#Na.C3.AFve_mark-and-sweep
http://en.wikipedia.org/wiki/Cheney

http://en.wikipedia.org/wiki/Cheney’s_algorithm

https://github.com/bnoordhuis/node-heapdump

http://mrale.ph/blog/2011/12/18/v8-optimization-checklist.html
http://es5.github.com/
http://blog.caustik.com/2012/04/08/scaling-node-js-to-100k-concurrent-connections/
https://hacks.mozilla.org/2013/01/building-a-node-js-server-that-wont-melt-a-node-js-holiday-season-part-5/
https://gist.github.com/2000999
http://www.jiangmiao.org/blog/2247.html
http://blog.caustik.com/2012/04/08/scaling-node-js-to-100k-concurrent-connections/
http://blog.caustik.com/2012/04/11/escape-the-1-4gb-v8-heap-limit-in-node-js/
https://developers.google.com/v8/embed#handles
https://hacks.mozilla.org/2012/11/fully-loaded-node-a-node-js-holiday-season-part-2/

https://code.google.com/p/v8/wiki/V8Profiler

歡迎關注我的公眾號【node全棧】