RSS memory leak on highload

[baryshev]

RSS memory doesn't release after doing some intensive tasks (highload).

My environment

• CPU: Core i5 450M 2.4Ghz
• OS: Ubuntu Server 12.04 (64 bit)
• RAM: 4096Mb
• Node.JS verison: 0.8.14

How to reproduce leak

1. Download test case.
2. Start node server.js.
3. Start node client.js.
4. Wait until RSS memory usage of node server.js rise up to 250-300Mb (or more).
5. Stop client.js and wait some time to give server.js time to complete all tasks.
6. If heap memory hasn't released you may start client.js for a short time again, to get GC of server.js work.

Expected result

RSS memory will be released as well as a heap memory and will be comparable with initial values.

Actual result

Heap memory released successfully, but RSS memory not.

My results:

Before test:

{ rss: 9768960, heapTotal: 6131200, heapUsed: 2604752 }

After test:

{ rss: 184217600, heapTotal: 6114560, heapUsed: 2660472 }

Related discussions

• High memory usage (or memleak?) websockets/ws#43
• http://grokbase.com/t/gg/nodejs/12ab62nmvb/is-growing-rss-something-to-worry-about
• https://groups.google.com/d/topic/nodejs/7EixhOfY2Ds/discussion

[superfeedr]

I believe we're seeing the same error. Thanks @baryshev for your thorough testing and debugging!

[bnoordhuis]

I see no memory leaks with your example. You are however buffering up a lot of data, which explains the growing RSS.

I've said it before and I'll say it again: RSS is an extremely poor metric for determining memory leaks. malloc implementations are very reluctant to return memory to the system even under ideal circumstances (i.e. no heap fragmentation). Here is a gist that demonstrates that.

[superfeedr]

@bnoordhuis Do you know of any tool/technique to see what are these buffers that are being allocated and how we can hopefully reduce their amount?

[bnoordhuis]

@superfeedr You can use something node-inspector or node-heapdump to create and inspect heap snapshots.

Regarding the test case (which I'll post here for the sake of posterity):

var server = net.createServer(function (socket) {
  socket.on('data', function() {
    setTimeout(function() {
      for (var i = 0; i < 100000; i++) {
        var d = new Date();
        socket.write(d.toString());
      }
    }, 10);
  });
});

It writes data to the socket without checking the return value of write(). The core logic should be rewritten to something like this:

var i = 1e5;
function f() {
  for (; i > 0; --i)
    if (socket.write(d.toString()) === false) // the strict check is not optional
      return socket.on('drain', f);
}
f();

[superfeedr]

@bnoordhuis But wait, I thought Buffers were outside of the heap?
I understand RSS is not the right metric to check for leaks, but our heap just stays reasonnably small (at most 100MB), while RSS explodes (can go easily to 1GB). We want to know what's in there, because this growing RSS (whether it's a leak or not) causes trouble and forces the machine to start swapping.

[bnoordhuis]

But wait, I thought Buffers were outside of the heap?

Yes, but as of commit 6a128e0 (v0.8.12 and up) they're reported properly in heap snapshots.

[superfeedr]

Brilliant! Back to exploration. Thanks for the precious help.
I expect though that they're not part of process.memoryUsage()'s heapTotal?

[bnoordhuis]

I expect though that they're not part of process.memoryUsage()'s heapTotal?

Indeed, but you can find out their total size with the statistics extension:

$ node --track_gc_object_stats -p 'Buffer(10*1024*1024); getV8Statistics()'
{ total_committed_bytes: 35635200,
  new_space_live_bytes: 391880,
  new_space_available_bytes: 656464,
  new_space_commited_bytes: 1048576,
  old_pointer_space_live_bytes: 524288,
  old_pointer_space_available_bytes: 0,
  old_pointer_space_commited_bytes: 524288,
  old_data_space_live_bytes: 196608,
  old_data_space_available_bytes: 0,
  old_data_space_commited_bytes: 196608,
  code_space_live_bytes: 1019904,
  code_space_available_bytes: 0,
  code_space_commited_bytes: 1019904,
  cell_space_live_bytes: 98304,
  cell_space_available_bytes: 0,
  cell_space_commited_bytes: 98304,
  lo_space_live_bytes: 0,
  lo_space_available_bytes: 1498414848,
  lo_space_commited_bytes: 0,
  amount_of_external_allocated_memory: 10485816 } # <- this

[spollack]

@bnoordhuis how do i get access to that extension? I tried the command line above, and node tells me it doesn't recognize this flag --track_gc_object_stats. I tried this on 0.8.18 and 0.8.14. Thanks!

node --track_gc_object_stats -p -e 'Buffer(10_1024_1024); getV8Statistics();'
Error: unrecognized flag --track_gc_object_stats
Try --help for options

Buffer(10_1024_1024); getV8Statistics();
^
ReferenceError: getV8Statistics is not defined
at eval:1:23
at Object. (eval-wrapper:6:22)
at Module._compile (module.js:449:26)
at evalScript (node.js:282:25)
at startup (node.js:76:7)
at node.js:627:3

[bnoordhuis]

@spollack It's only available in the master branch, the V8 version in v0.8 is too old.

[bobrik]

@bnoordhuis my rss is increasing, but amount_of_external_allocated_memory stays low:

Before gc():

{"rss":265080832,"heapTotal":56172032,"heapUsed":8697768}
{
    "total_committed_bytes": 57688064,
    "new_space_live_bytes": 4027464,
    "new_space_available_bytes": 12749592,
    "new_space_commited_bytes": 33554432,
    "old_pointer_space_live_bytes": 2159320,
    "old_pointer_space_available_bytes": 12812072,
    "old_pointer_space_commited_bytes": 14971392,
    "old_data_space_live_bytes": 1095272,
    "old_data_space_available_bytes": 1165208,
    "old_data_space_commited_bytes": 2260480,
    "code_space_live_bytes": 1219904,
    "code_space_available_bytes": 1839808,
    "code_space_commited_bytes": 3059712,
    "cell_space_live_bytes": 31120,
    "cell_space_available_bytes": 99952,
    "cell_space_commited_bytes": 131072,
    "lo_space_live_bytes": 0,
    "lo_space_available_bytes": 1476361984,
    "lo_space_commited_bytes": 0,
    "amount_of_external_allocated_memory": 1081624
}

After gc():

{"rss":258056192,"heapTotal":49980416,"heapUsed":4513704}
{
    "total_committed_bytes": 51396608,
    "new_space_live_bytes": 2080,
    "new_space_available_bytes": 16774976,
    "new_space_commited_bytes": 33554432,
    "old_pointer_space_live_bytes": 2127400,
    "old_pointer_space_available_bytes": 6652376,
    "old_pointer_space_commited_bytes": 8779776,
    "old_data_space_live_bytes": 1802640,
    "old_data_space_available_bytes": 457840,
    "old_data_space_commited_bytes": 2260480,
    "code_space_live_bytes": 1145440,
    "code_space_available_bytes": 1914272,
    "code_space_commited_bytes": 3059712,
    "cell_space_live_bytes": 30304,
    "cell_space_available_bytes": 100768,
    "cell_space_commited_bytes": 131072,
    "lo_space_live_bytes": 0,
    "lo_space_available_bytes": 1482653440,
    "lo_space_commited_bytes": 0,
    "amount_of_external_allocated_memory": 1065128
}

heap dump file is around 250mb, but chrome says that it is only 5.1mb. What am I missing? My app processes around 20m simple requests per day and becomes less responsible (3ms on the first day -> up to 500ms on the third day). I don't use compiled modules, only redis and empty-gif.

node.js 0.10.10

[trevnorris]

@bobrik dead thread probably won't get you many responses. i'd say throw this on the mailing list. and some code is going to much more helpful.

[ApsOps]

@superfeedr Hi. It's pretty late, but were you able to figure out the reason? I'm facing this behavior in one of my apps as well:

I understand RSS is not the right metric to check for leaks, but our heap just stays reasonnably small (at most 100MB), while RSS explodes (can go easily to 1GB). We want to know what's in there, because this growing RSS (whether it's a leak or not) causes trouble and forces the machine to start swapping.