Re: [nodejs_jp:648] socket.ioのheartbeat時におけるメモリリークについて

[Shigeki Ohtsu]

大津です。

>> なので，本当にメモリリークが発生していていずれはヒープが
>> 枯渇するのか，それともフル GC が先延ばしにされているだけ
>> なのかを見極める必要があるのではないかと思います．

そういえば、node で手動GCできる方法があったなぁと思いだしたので、チョッ
ト試してみました。0.1秒毎に heartbeat を出し、クライアントから受け取った
らすかさずGCする例です。

https://gist.github.com/2840165

600heartbeat毎にメモリ状況を出力した結果です。超マメGCは見事に heap使用
量がそろってますね。他方 Node にお任せGCはバラバラ。

BenもMLで今の Node の 「idle だったら GC 呼び出す」のはいくつかのケース
でうまくいかないので今後アルゴリズムを変えると書いていましたので、今回の
ケースもそれに当てはまるケースじゃないですかね。

heartbeat受け取る毎に手動GC (node-v0.6.18)
> unixjp:~/tmp/socketio> node --nouse_idle_notification --expose_gc test.js
>    info  - socket.io started
> client connected
> 0 { rss: 21876736, heapTotal: 16209952, heapUsed: 4284792 } 'delta:' { rss: 
> 0, heapTotal: 0, heapUsed: 0 }
> 600 { rss: 21417984, heapTotal: 15616032, heapUsed: 3648380 } 'delta:' { rss: 
> -458752, heapTotal: -593920, heapUsed: -636412 }
> 1200 { rss: 21422080, heapTotal: 24004640, heapUsed: 3644136 } 'delta:' { 
> rss: 4096, heapTotal: 8388608, heapUsed: -4244 }
> 1800 { rss: 21430272, heapTotal: 24004640, heapUsed: 3644208 } 'delta:' { 
> rss: 8192, heapTotal: 0, heapUsed: 72 }
> 2400 { rss: 21434368, heapTotal: 24004640, heapUsed: 3644256 } 'delta:' { 
> rss: 4096, heapTotal: 0, heapUsed: 48 }
> 3000 { rss: 21438464, heapTotal: 24004640, heapUsed: 3644292 } 'delta:' { 
> rss: 4096, heapTotal: 0, heapUsed: 36 }
> 3600 { rss: 21446656, heapTotal: 24004640, heapUsed: 3644332 } 'delta:' { 
> rss: 8192, heapTotal: 0, heapUsed: 40 }
> 4200 { rss: 21450752, heapTotal: 24004640, heapUsed: 3644364 } 'delta:' { 
> rss: 4096, heapTotal: 0, heapUsed: 32 }
> 4800 { rss: 21454848, heapTotal: 24004640, heapUsed: 3644704 } 'delta:' { 
> rss: 4096, heapTotal: 0, heapUsed: 340 }
> 5400 { rss: 21463040, heapTotal: 24004640, heapUsed: 3644760 } 'delta:' { 
> rss: 8192, heapTotal: 0, heapUsed: 56 }
> 6000 { rss: 21467136, heapTotal: 24004640, heapUsed: 3644792 } 'delta:' { 
> rss: 4096, heapTotal: 0, heapUsed: 32 }

Nodeによるお任せGC (node-v0.6.18)
> unixjp:~/tmp/socketio> node test.js
>    info  - socket.io started
> client connected
> 0 { rss: 23203840, heapTotal: 17729184, heapUsed: 9885436 } 'delta:' { rss: 
> 0, heapTotal: 0, heapUsed: 0 }
> 600 { rss: 25260032, heapTotal: 17729184, heapUsed: 12557360 } 'delta:' { 
> rss: 2056192, heapTotal: 0, heapUsed: 2671924 }
> 1200 { rss: 25821184, heapTotal: 18300640, heapUsed: 11676544 } 'delta:' { 
> rss: 561152, heapTotal: 571456, heapUsed: -880816 }
> 1800 { rss: 24408064, heapTotal: 16797408, heapUsed: 5267092 } 'delta:' { 
> rss: -1413120, heapTotal: -1503232, heapUsed: -6409452 }
> 2400 { rss: 24428544, heapTotal: 16797408, heapUsed: 7849444 } 'delta:' { 
> rss: 20480, heapTotal: 0, heapUsed: 2582352 }
> 3000 { rss: 12955648, heapTotal: 5329568, heapUsed: 3973844 } 'delta:' { rss: 
> -11472896, heapTotal: -11467840, heapUsed: -3875600 }
> 3600 { rss: 13090816, heapTotal: 5460128, heapUsed: 4127740 } 'delta:' { rss: 
> 135168, heapTotal: 130560, heapUsed: 153896 }
> 4200 { rss: 13225984, heapTotal: 5590688, heapUsed: 4258476 } 'delta:' { rss: 
> 135168, heapTotal: 130560, heapUsed: 130736 }
> 4800 { rss: 12963840, heapTotal: 5321408, heapUsed: 3672084 } 'delta:' { rss: 
> -262144, heapTotal: -269280, heapUsed: -586392 }
> 5400 { rss: 13103104, heapTotal: 5451968, heapUsed: 3826204 } 'delta:' { rss: 
> 139264, heapTotal: 130560, heapUsed: 154120 }
> 6000 { rss: 13238272, heapTotal: 6622944, heapUsed: 3955288 } 'delta:' { rss: 
> 135168, heapTotal: 1170976, heapUsed: 129084 }