Memory Leak

[nickydonna]

We've been experiencing a memory leak in our node servers. Over the course of a day or so the memory in our servers started to fill until we got an alert and had to restart the app. We added new relic to check the node VM memory:

Upon debugging and testing we've come to the conclusion that the leak could be in express. We did some test on a clean express server, printing the heap before and after a lot of request and we see the memory increasing but never going back to the initial value.

We tested on various versions of Node and two versions of express (4.16.2 and 4.14.1) and we had the same results.

I'll add the last test setup so you can reproduce it.

Tested on OSX 10.12.6
Node 7.6.0
Express 4.16.1

Code

var express = require('express');

var app = express();

app.get('/', function(req, res) {
  res.status(200).send('asdf');
  res.end();
});

function generateHeapDumpAndStats() {
  //1. Force garbage collection every time this function is called
  try {
    global.gc();
  } catch (e) {
    console.log("You must run program with 'node --expose-gc'");
    process.exit();
  }

  //2. Output Heap stats
  var heapUsed = process.memoryUsage().heapUsed;
  console.log('Program is using ' + heapUsed + ' bytes of Heap.');
}

const PORT = process.env.PORT || 9000;

app.listen(PORT, function() {
  console.log(`App listening on port ${PORT}!`);
});

setInterval(generateHeapDumpAndStats, 3000);

run with node --expose-gc server.js

autocannon command autocannon -a100000 -c5 http://localhost:9000/

Results:

This is just one of the many test we made, all with similar results

[dougwilson]

Thanks for the report, we will look into this ASAP. Do you think this is the same as #3413 or different?

[nickydonna]

@dougwilson I don't think so, but I did the same test with a basic node server and I seem to have the same issue

// [START app]
const http = require('http');

const server = http.createServer(app);

function generateHeapDumpAndStats() {
  //1. Force garbage collection every time this function is called
  try {
    global.gc();
  } catch (e) {
    console.log("You must run program with 'node --expose-gc'");
    process.exit();
  }

  //2. Output Heap stats
  var heapUsed = process.memoryUsage().heapUsed;
  console.log('Program is using ' + heapUsed + ' bytes of Heap.');
}

function app(req, res) {
  res.statusCode = 200;
  res.end('Hello, world!');
}

// Start the server
const PORT = process.env.PORT || 9000;
server.listen(PORT, () => {
  console.log(`App listening on port ${PORT}`);
});

setInterval(generateHeapDumpAndStats, 3000);
// [END app]

At this point we are really confused 😕 . Maybe you can help us find out if we are doing something wrong in the way we measure the memory consumption

[dougwilson]

So I'm trying to reproduce the issue with the provided code and I'm not seeing the memory growth, unless I'm missing something? I'm using Express 4.16.1 and Node.js 7.6.0. Running that autocannon command 4 times in a row gave me the below output from the app:

App listening on port 9000!
Program is using 7195160 bytes of Heap.
Program is using 7173480 bytes of Heap.
Program is using 7174480 bytes of Heap.
Program is using 7954848 bytes of Heap.
Program is using 8010144 bytes of Heap.
Program is using 8060768 bytes of Heap.
Program is using 7961960 bytes of Heap.
Program is using 7430704 bytes of Heap.
Program is using 7425968 bytes of Heap.
Program is using 8041216 bytes of Heap.
Program is using 8072720 bytes of Heap.
Program is using 8082880 bytes of Heap.
Program is using 8013416 bytes of Heap.
Program is using 7464704 bytes of Heap.
Program is using 7463344 bytes of Heap.
Program is using 7954032 bytes of Heap.
Program is using 8082480 bytes of Heap.
Program is using 8030456 bytes of Heap.
Program is using 7759072 bytes of Heap.
Program is using 7685632 bytes of Heap.
Program is using 7496672 bytes of Heap.
Program is using 7495392 bytes of Heap.
Program is using 7206880 bytes of Heap.
Program is using 7200552 bytes of Heap.
Program is using 7181624 bytes of Heap.
Program is using 7181624 bytes of Heap.
Program is using 7616424 bytes of Heap.
Program is using 7632480 bytes of Heap.
Program is using 7628984 bytes of Heap.
Program is using 7557536 bytes of Heap.
Program is using 7390816 bytes of Heap.
Program is using 7389536 bytes of Heap.
Program is using 7215256 bytes of Heap.
Program is using 7212776 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193848 bytes of Heap.
Program is using 7193560 bytes of Heap.
Program is using 7193560 bytes of Heap.

It seems to just be sitting at the same heap memory as it started. Taking a heapdump before and after I'm not seeing any objects hanging around, either. What objects are you seeing being held in the heapdump? Am I missing a step somewhere?

Here is what I did:

1. Install Express 4.16.1
2. Copy and pasted your app into app.js
3. Started it with ./node-v7.6.0-darwin-x64/bin/node --expose-gc app.js
4. Ran autocannon -a100000 -c5 http://localhost:9000/ 4 times, with 10 seconds between each run
5. Copied the output from app.js above.

I then did it all again taking a heap dump between 3 and 4 and again between 4 and 5.

[dougwilson]

but I did the same test with a basic node server and I seem to have the same issue

There is always a possibility that the memory leak, if it's there, can be in Node.js's HTTP server implementation. Express doesn't really add much around it, and that is where all the complexity lies within a bare-bones Express app.

[machadogj]

Hi @dougwilson I tried in my computer with the same instructions, and here's my output:
(notice how before each autocannon run I hit enter a few times)

Program is using 7196264 bytes of Heap.
Program is using 7178296 bytes of Heap.
Program is using 7179296 bytes of Heap.
Program is using 6386520 bytes of Heap.
Program is using 6353008 bytes of Heap.
Program is using 6340896 bytes of Heap.
Program is using 6340896 bytes of Heap.
Program is using 6340896 bytes of Heap.
Program is using 6340896 bytes of Heap.
Program is using 6340896 bytes of Heap.
Program is using 6340896 bytes of Heap.







Program is using 6340896 bytes of Heap.
Program is using 7922128 bytes of Heap.
Program is using 8010464 bytes of Heap.
Program is using 8043640 bytes of Heap.
Program is using 7715384 bytes of Heap.
Program is using 7434184 bytes of Heap.
Program is using 7430984 bytes of Heap.
Program is using 7134456 bytes of Heap.
Program is using 7126208 bytes of Heap.
Program is using 7107280 bytes of Heap.
Program is using 7107280 bytes of Heap.
Program is using 7107280 bytes of Heap.
Program is using 7107280 bytes of Heap.
Program is using 7107280 bytes of Heap.




Program is using 7107280 bytes of Heap.
Program is using 8007352 bytes of Heap.
Program is using 8078800 bytes of Heap.
Program is using 8078080 bytes of Heap.
Program is using 8024992 bytes of Heap.
Program is using 7488064 bytes of Heap.
Program is using 7486784 bytes of Heap.
Program is using 7202264 bytes of Heap.
Program is using 7196696 bytes of Heap.
Program is using 7177768 bytes of Heap.
Program is using 7177768 bytes of Heap.
Program is using 7177768 bytes of Heap.
Program is using 7177768 bytes of Heap.
Program is using 7177768 bytes of Heap.
Program is using 7177768 bytes of Heap.
Program is using 7177768 bytes of Heap.

• ./node-v7.6.0-darwin-x64/bin/node --expose-gc app.js
• autocannon -a100000 -c5 http://localhost:9000/

[dfejgelis]

FWIW I've tried this in my PC (but with node 9.3.0)

$ node --expose-gc server.js
App listening on port 9000!
Program is using 7828424 bytes of Heap.
Program is using 7828424 bytes of Heap.
Program is using 7828376 bytes of Heap.
Program is using 7828424 bytes of Heap.

(started `autocannon -a1000000 -c5 http://localhost:9000/`)

Program is using 7888440 bytes of Heap.
Program is using 8456512 bytes of Heap.
Program is using 8524384 bytes of Heap.
Program is using 8535816 bytes of Heap.
Program is using 8519464 bytes of Heap.
Program is using 8528952 bytes of Heap.
Program is using 8515240 bytes of Heap.
Program is using 8537512 bytes of Heap.
Program is using 8566472 bytes of Heap.
Program is using 8604776 bytes of Heap.
Program is using 8608696 bytes of Heap.
Program is using 8577368 bytes of Heap.
Program is using 8554776 bytes of Heap.
Program is using 8584824 bytes of Heap.
Program is using 8560440 bytes of Heap.
Program is using 8577472 bytes of Heap.
Program is using 8561192 bytes of Heap.
Program is using 8564896 bytes of Heap.
Program is using 8573520 bytes of Heap.
Program is using 8611112 bytes of Heap.
Program is using 8552472 bytes of Heap.
Program is using 8596824 bytes of Heap.
Program is using 8593448 bytes of Heap.
Program is using 8593504 bytes of Heap.
Program is using 8581464 bytes of Heap.
Program is using 8590016 bytes of Heap.
Program is using 8597592 bytes of Heap.
Program is using 8601000 bytes of Heap.
Program is using 8547752 bytes of Heap.
Program is using 8611344 bytes of Heap.
Program is using 8567128 bytes of Heap.
Program is using 8603032 bytes of Heap.
Program is using 8569416 bytes of Heap.
Program is using 8573712 bytes of Heap.
Program is using 8578104 bytes of Heap.
Program is using 8578984 bytes of Heap.
Program is using 8572328 bytes of Heap.
Program is using 8599016 bytes of Heap.
Program is using 8572664 bytes of Heap.
Program is using 8573664 bytes of Heap.
Program is using 8606448 bytes of Heap.
Program is using 8573648 bytes of Heap.
Program is using 8595400 bytes of Heap.
Program is using 8568496 bytes of Heap.
Program is using 8567816 bytes of Heap.
Program is using 8570800 bytes of Heap.
Program is using 8581992 bytes of Heap.
Program is using 8596520 bytes of Heap.
Program is using 8472504 bytes of Heap.

(autocannon ended)

Program is using 7949488 bytes of Heap.
Program is using 7949440 bytes of Heap.
Program is using 7949440 bytes of Heap.
Program is using 7949488 bytes of Heap.
Program is using 7949488 bytes of Heap.
Program is using 7949488 bytes of Heap.
Program is using 7949440 bytes of Heap.
Program is using 7949488 bytes of Heap.
Program is using 7949488 bytes of Heap.
Program is using 7949440 bytes of Heap.
Program is using 7949488 bytes of Heap.
Program is using 7949488 bytes of Heap.
Program is using 7949440 bytes of Heap.
Program is using 7949488 bytes of Heap.

[dougwilson]

So are you guys seeing the memory leak? I put it on a loop since my last update and autocannon has run now 1231 times and the measurement says 719450 bytes. That is pretty much the same as my starting size of 7193660. I'm not sure how much I can really help if I cannot reproduce a memory leak, because to diagnose a memory leak, the first step is to use heapdumps to see what objects are actually leaking, and I keep taking the heapdumps and there is basically nothing in there between the autocannon runs, so I can't tell what would be leaking in order to know what Express needs to change.

Any hints / tips on what objects you're seeing leaking would be super helpful. For example, can you take a heapdump on your end before the autocannons and after you have the leak so we do a comparison to see what the leaking objects are?

[nickydonna]

@dougwilson I did some heap dumps, it seems that after the first run some of the memory is used for strings and another objects that seem to make sense, but after a second autocannon run there are some object that I don't know how to debug

• The first snapshot is after the server starts and the memory has been stabilized.
• The second is after an autocannon run and the memory has been stabilized.
• The third is after a second autocannon run and the memory has been stabilized.

There is a timer but I believe its because of the setInterval for the heap size printing.

I just realized I did the test on an simple node HTTP server, but if you can help determine that the bug is actually on the Node HTTP implementation I'll make the issue in the node repo

Here is the server code.

// [START app]
const http = require('http');

const server = http.createServer(app);
const heapdump = require('heapdump');

heapdump.writeSnapshot('./' + Date.now() + '.heapsnapshot');

function generateHeapDumpAndStats() {
  //1. Force garbage collection every time this function is called
  try {
    global.gc();
  } catch (e) {
    console.log("You must run program with 'node --expose-gc'");
    process.exit();
  }

  //2. Output Heap stats
  var heapUsed = process.memoryUsage().heapUsed;
  console.log('Program is using ' + heapUsed + ' bytes of Heap.');
}

function app(req, res) {
  res.statusCode = 200;
  res.end('Hello, world!');
}

// Start the server
const PORT = process.env.PORT || 9000;
server.listen(PORT, () => {
  console.log(`App listening on port ${PORT}`);
});

setInterval(generateHeapDumpAndStats, 3000);
// [END app]

Thanks for all the help

Archive.zip

[Starystars67]

I too am getting memory leak related issues while using express, has this post made any progress since creation?

[dougwilson]

I have not been able to reproduce the leak locally with the provided code, and neither has the Node.js core team. We need to be able to reproduce it to make progress, so any help getting it reproduced would be the next step. Another possibility is if someone is willing to allow myself or someone remote access to debug on a machine that is reproducing the issue, perhaps as a Skype call even.

[Starystars67]

@dougwilson You can Remote connect to my local machine where I am developing if it will help? When is best for you, I am free for the next 2 hours.

[dougwilson]

Hi @Starystars67 I am at work for the next 6 hours, so unable to do so right now. If you're available to do so over the weekend that would work, or if there is another time that is good, let me know and we can work something out 👍

[Starystars67]

Do you have discord? if so please add me on there and when you are available drop me a message and ill see what I can sort?

Titch2000#6388

[dougwilson]

I've heard of it but don't have an account there. I'll sign up for one when I get off tonight 👍

[nickydonna]

@Starystars67 we will try to make a heavy load test next week to try to reproduce the same issues we are having in production

[Starystars67]

Hi @dougwilson, Are you still interested in connecting to my local system to observe the issue?

[dougwilson]

I'm still interested, I haven't forgotten. I just haven't gotten around to creating an account yet since it's a holiday weekend (in thr US).

[Starystars67]

Okay buddy, do you have any idea on when you do think would be best for you?

[dougwilson]

So tomorrow after work would be the next best time: Feb 20 around 7pm US eastern time.

[Starystars67]

okay will make sure that I am free then.

[dougwilson]

Sounds good. I'll get a Discord account setup prior to then so we can use it to screen share.

[dougwilson]

Just as a heads up work went over today by half an hour, and just leaving my office now. Commute takes about an hour so will be about half an hour late. When I get home I'll create the Discord account and will contact you there 👍

[Starystars67]

Okay, just as a side note i am in the UK so please keep in mind it is already late but i am getting desperate in trying to solve the issue so i will stay up. See you soon

[dougwilson]

Yes, very sorry, I couldn't control getting out on time. I sent you a friend request on Discord just now.

[Starystars67]

i understand that buddy, just dont want to be messed around either

[dougwilson]

Yea. So I'm not sure how to use Discord. I sent the friend request to your username above. Just message me on there 👍

[igor-savin-ht]

@Starystars67 Any updates?

[Starystars67]

Hi @igor-savin-ht, currently if you need something ASAP make sure you are not using the argument --inspect as this increases the memory leak size significantly, other than that @dougwilson is trying to see if he can locate the specific issue though it seems to be within Node v8 it's self. Node developers have been contacted though.

[nickydonna]

@Starystars67 I downgraded to 4.15.2, but I don't know if it will work

[Starystars67]

@donnanicolas Thanks! will get back to you when i can on the result.

[TheCrabity]

For those of you who are testing:

You need to keep sustained traffic coming. For me, around 1 million / hour. And after about 30 minutes the leak becomes noticeable, and continues to grow. This is likely more related to the underlying http stack, as opposed to express itself, from what we can gather. Seems folks are having similar issues using Requests as well.

[nickydonna]

@Hermities we believe the same as you, but we haven't been able to reproduce it locally

[Starystars67]

when my self and @dougwilson were testing we reduced it all the way down to this:

// set up ======================================================================
// get all the tools we need
var ejs = require('ejs');
var http = require('http');
var path = require('path');

var server = http.createServer(function(req, res) {
	var filename = path.join(__dirname, 'index.min.ejs');
	ejs.renderFile(filename, function (err, str) {
		res.end(str);
	});
});

// launch ======================================================================
server.listen(81)

function generateHeapDumpAndStats() {
    //1. Force garbage collection every time this function is called
    try {
        global.gc();
    } catch (e) {
        console.log("You must run program with 'node --expose-gc'");
        process.exit();
    }

    //2. Output Heap stats
    var heapUsed = process.memoryUsage().heapUsed;
    console.log('Program is using ' + heapUsed + ' bytes of Heap.');
}

setInterval(generateHeapDumpAndStats, 3000);

and were still getting the leak

[wesleytodd]

Are the other people in this thread using ejs?

Also, why go through the whole thing with adding manual garbage collection to the mix? Just make an actual reduced test case like I posted and use external tools to measure. If you are seeing different behavior when run with --inspect then you can just start by proving the process is growing using other tools, then dig in with --inspect to find the actual issue. Anything else has too many factors to be a good reduced test case.

[TheCrabity]

Not using ejs here.

[wesleytodd]

I have been running a siege now for a while, over an hour, with no leak. I started a fresh process just to compare the mem usage (but without --inspect) and it seems stable and comparable (remember the inspector will increase baseline overhead).

[Starystars67]

@wesleytodd Is that with the latest version or the version @donnanicolas mentioned?

[wesleytodd]

Latest express version, 4.16.2.

[TheCrabity]

Perhaps the size of the return has an impact? All of mine are sending decent sized json object in the response.

[wesleytodd]

Can you post your application code? Or provide a workable application which exhibits the leak you are seeing? Because none of the examples posted here reproduce a leak for me.

[Starystars67]

the version i posted causes a leak
and as for a response the ejs file contains the following:

<!DOCTYPE html>
<html lang="en">
</html>

and this was enough to cause a leak, a small one but a leak non the less

[wesleytodd]

@Starystars67 Can you remove the in process memory management stuff and try again?

EDIT:

I am not sure why we are here testing an ejs and core http version in the express repo. If you think this is an ejs issue, make a reduced test for ejs. If you think it is an http leak, write that test case. This just seems to be the wrong place to discuss if the issue is not express related.

[Starystars67]

@wesleytodd sure, how would you like me to monitor memory? is inspect what you was using or was you using something else?

[wesleytodd]

Ok, threw in an ejs.renderFile just to be thorough here, and it seems pretty clear that that has a bad leak. I would open an issue on that repo with these details.

[TheCrabity]

I'll work on a slimmed down test for the non ejs leak we are seeing. I've confirmed it across serveral servers and versions. The hard part is slimming it down and still productions the leak, tho.

[dougwilson]

Hi @Hermities any progress on that? If you need me to come do a screen share where I can debug the leak through your code, I can do that too 👍 Unless there is a clear non-ejs-related leak shown in a few weeks, I'm going to close this issue without something concrete we can investigate and act on. I'm not dismissing your memory leaks, and want to fix them as much as you do, but if I don't have anything to reproduce and trace through, I have nothing to act on and no way to address them in the Express.js code base. Applications can get very complex and you have many, many modules in the mix, any one of which can cause a leak, so I'm not sure how you were able to narrow down that it is specifically Express.js that is leaking but are not able to provide a reproduce case we can take a look at...? Any guidance you can provide us to track the leak down and work on a fix is very appreciated 🙏

[Starystars67]

Hi @dougwilson Did we not strip it down past ejs to the point that it was using only NodeJS modules only? I thought the issue came down to NodeJS its self or am I wrong? Thanks :)

[dougwilson]

Yes @Starystars67 in your case that is what we did. I'm sorry there are multiple people's memory leaks all in this same issue, and it seems as long as this issue is open, a new person comes along with a memory leak, spinning this issue further out of control and no longer able to focus on the previous memory leak diagnosis.

[Starystars67]

@dougwilson Okay Sir, Thank you. did we get anywhere with contacting NodeJS Developers in getting my issue fixed?

[dougwilson]

I was in contact with an inspector member by email (since the issue was only there in our reproduction when the inspector was attached) and they could reproduce it and I'm not sure if I heard back because I'm still working through the 500+ email backlog from the past week or so (which is why I'm circling back on this issue). You're always welcome to create an issue at https://github.com/nodejs/node/issues if you want to get a direct line to the Node.js team if you don't want to wait on a chain of a few people :)

[Starystars67]

haha I see, in an effort to reduce your backlog I will create an issue yes. If you hear back before I should let me know and I will close the issue I will create now.

EDIT*
Further to my original message I shall await for your reply on if the Inspector member got back to you, as not to bring the issue up twice causing unnecessary issues for them.

[dougwilson]

Closing per #3552 (comment)

[raoulus]

@nickydonna I am very curious what the end of the story was? Were you able to fix it? It's two years later but I am also seeing a similar thing in one production app..