[3.2.0] Potential memory leak

[Cinderella-Man]

Recently I was stress testing my API and discovered that even very simple net server has a memory leaks. Is it possible that there's something wrong with it?

Server code:

"use strict"

var net = require('net');

// Keep track of the chat clients
var clients = [];

function clean() {
 global.gc();
 console.log('Current memory usage: ', process.memoryUsage());
 setTimeout(clean, 30000);
}

setTimeout(clean, 30000);

var proxy = net.createServer(function (socket) {

 // Identify this client
 socket.name = socket.remoteAddress + ":" + socket.remotePort

 // Put this new client in the list
 clients.push(socket);

 socket.on('close', function () {
 clients.splice(clients.indexOf(socket), 1);
 socket = null;
 });

 socket.on('error', function (err) {
 clients.splice(clients.indexOf(socket), 1);
 socket = null;
 });
});

console.log('Current memory usage: ', process.memoryUsage());

proxy.listen(2919);

Testing client bash script:

#!/bin/bash

for i in $(seq 1 1 10000)
do
 curl -m0.001 http://127.0.0.1:2919/;
done

Starting iojs server(3.2.0):

$ node --expose-gc test.js
Current memory usage: { rss: 21942272, heapTotal: 9275392, heapUsed: 3732936 }
Current memory usage: { rss: 36179968, heapTotal: 26806272, heapUsed: 4428112 }
Current memory usage: { rss: 47865856, heapTotal: 44349184, heapUsed: 4496016 }
Current memory usage: { rss: 47325184, heapTotal: 40221440, heapUsed: 4472480 }

After 10k calls server memory consumption increased from 21 to 45.5MB. Is that scripts' fault?

[Fishrock123]

@Cinderella-Man Does this also happen with io.js 2.5.0?

[mscdex]

From what I'm seeing, the server process stabilizes at ~59-60MB rss, even if you keep restarting the client bash script.

The stabilized memory amount can be improved a little bit (~2MB total on average) by draining the socket buffers sooner by adding socket.resume(); at the end of the socket connection handler.

Additionally, if you force the gc() to run more often (e.g. every 5 seconds vs. every 30 seconds), the stabilized memory amount is much lower, ~31-33MB.

[mscdex]

With io.js v2.5.0 I'm seeing roughly the same memory differences, except the rss has dropped uniformly for all scenarios by ~1MB.

[rvagg]

the new Buffer implementation makes rss much more unstable over longer runs now than it used to, thanks to something in ArrayBuffer, zoom out to 2d or 7d and look at the bottom graph: http://128.199.216.28:3000/dashboard/db/memory-tests

[ChALkeR]

1. A single gc() run does not necessary clean all the garbage.
2. RSS generally doesn't decrease even after the memory is free-d, because the memory allocator behaves that way. That memory is not returned to the system, but is used later for further allocations done by the process. It's not node/io.js fault, even a simple c++ program behaves that way: it depends on the size of allocated memory chunks — large chunks are allocated using mmap and are returned to the system (rss decreases), small chunks are allocated using sbrk and are not returned to the system (rss does not decrease). Given that the most common use-cases (in most programs) involve allocations of small memory chunks, you get almost non-decreasing RSS.

My results for your script (given that by -m0.001 you meant curl to time-out after 1 ms, and global.gc() is meant to do the same as gc()):

Current memory usage: { rss: 21901312, heapTotal: 9275392, heapUsed: 3734576 }
Current memory usage: { rss: 45281280, heapTotal: 28870144, heapUsed: 4428680 }
Current memory usage: { rss: 63672320, heapTotal: 45381120, heapUsed: 4495424 }
Current memory usage: { rss: 59326464, heapTotal: 40221440, heapUsed: 4457776 }
Current memory usage: { rss: 58126336, heapTotal: 40221440, heapUsed: 4093264 }
Current memory usage: { rss: 59105280, heapTotal: 40221440, heapUsed: 4089504 }
Current memory usage: { rss: 59105280, heapTotal: 40221440, heapUsed: 3960528 }
Current memory usage: { rss: 58974208, heapTotal: 40221440, heapUsed: 3960416 }

Second client run on the same server:

Current memory usage: { rss: 59518976, heapTotal: 40221440, heapUsed: 4174544 }
Current memory usage: { rss: 59125760, heapTotal: 41253376, heapUsed: 4221008 }
Current memory usage: { rss: 60416000, heapTotal: 41253376, heapUsed: 4224464 }
Current memory usage: { rss: 58814464, heapTotal: 40221440, heapUsed: 4101888 }
Current memory usage: { rss: 59740160, heapTotal: 40221440, heapUsed: 4032056 }
Current memory usage: { rss: 58773504, heapTotal: 40221440, heapUsed: 3983840 }
Current memory usage: { rss: 59740160, heapTotal: 40221440, heapUsed: 3983840 }
Current memory usage: { rss: 59740160, heapTotal: 40221440, heapUsed: 3983840 }

You could see that both RSS and heapUsed have stabilized.

While @rvagg is correct here about the new Buffer implementation, this specific test-case does not look problematic to me. Also, the problems with Buffer are not memory leaks.

Btw, speaking of 1.: if you replace a gc() call with four subsequent gc() calls (I do not recommend doing that on a production server), you will see that heapUsed remains more stable (two client runs here):

Current memory usage: { rss: 22261760, heapTotal: 9275392, heapUsed: 3735464 }
Current memory usage: { rss: 40538112, heapTotal: 23710464, heapUsed: 3987672 }
Current memory usage: { rss: 58322944, heapTotal: 40221440, heapUsed: 3832872 }
Current memory usage: { rss: 58421248, heapTotal: 40221440, heapUsed: 3839944 }
Current memory usage: { rss: 58331136, heapTotal: 40221440, heapUsed: 3840568 }
Current memory usage: { rss: 58372096, heapTotal: 40221440, heapUsed: 3840928 }
Current memory usage: { rss: 58372096, heapTotal: 40221440, heapUsed: 3840928 }
Current memory usage: { rss: 58372096, heapTotal: 40221440, heapUsed: 3840928 }
Current memory usage: { rss: 58372096, heapTotal: 40221440, heapUsed: 3840864 }
Current memory usage: { rss: 58372096, heapTotal: 40221440, heapUsed: 3840864 }
Current memory usage: { rss: 58413056, heapTotal: 40221440, heapUsed: 3850144 }
Current memory usage: { rss: 58494976, heapTotal: 40221440, heapUsed: 3860896 }
Current memory usage: { rss: 58515456, heapTotal: 40221440, heapUsed: 3871040 }
Current memory usage: { rss: 58515456, heapTotal: 40221440, heapUsed: 3871464 }
Current memory usage: { rss: 58515456, heapTotal: 40221440, heapUsed: 3871464 }
Current memory usage: { rss: 58515456, heapTotal: 40221440, heapUsed: 3871464 }

[ChALkeR]

Should we close this?

[mscdex]

Closing this for now. If someone can prove that there is a continual leak that never stops, then we can reopen this at that time.