net.js - possible EventEmitter memory leak detected

[ghost]

I don't know exactly when this happens. But I know this is not caused by my code. This happens in Node v0.10.0. Line numbers have changed a little bit since then but the stack trace might be usefull:

(node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.
Trace
    at Socket.EventEmitter.addListener (events.js:160:15)
    at Socket.Readable.on (_stream_readable.js:653:33)
    at Socket.EventEmitter.once (events.js:179:8)
    at TCP.onread (net.js:512:26)
FATAL ERROR: Evacuation Allocation failed - process out of memory

[bnoordhuis]

But I know this is not caused by my code.

How do you know that? More details would be appreciated.

[ghost]

Unfortunately, I don't have any test cases prepared. It happens in this project https://github.com/archilimnadze/reverse-proxy-server . It's basically a one-file reverse proxy server receiving requests from the cluster module (using 4 cores in my case) and making proxy requests. Tell me what kind of more details can I provide and I'll do my best to get it.

[bnoordhuis]

Try instrumenting the .on() and .once() methods of req, res, req.socket and res.socket and trace the 'end' events. What I suspect happens is that 'end' event listeners keep getting added, either by node or by your code. The internal listener that node adds is probably the tipping point.

Example:

var on_ = req.on;
req.on = function() {
  console.log(arguments);
  console.trace();
  return on_.apply(this, arguments);
};

[isaacs]

@archilimnadze A standalone node-only test is best. Failing that, a standalone not-node-only test is second-best. It's not as helpful to just say it happens when you use XYZ module, without pointing to a set of steps to actually make it happen with that module.

[ghost]

I'll try to make a test case. Before that I know you can't do anything. Sorry.

-------- Original Message --------
Subject: Re: [node] net.js - possible EventEmitter memory leak detected
(#5108)
From: "Isaac Z. Schlueter" notifications@github.com
Date: Fri, March 22, 2013 9:47 am
To: joyent/node node@noreply.github.com
Cc: Archil Imnadze archil@imnadze.ge@archilimnadze A standalone node-only test is best. Failing that, a standalone not-node-only test is second-best. It's not as helpful to just say it happens when you use XYZ module, without pointing to a set of steps to actually make it happen with that module. —Reply to this email directly or view it on GitHub.

[ghost]

I'm closing it until I find it reproducible.

[cthurston]

Last week tried to update a project build on Express to node 10.1. However, ran into this bug as well. If page is reloaded twice quickly or several requests are made by clicking a button, the memory leak warning is triggered and node.js runs 100% cpu.

Centos 6.4

I will try to gather more information and trace the error.

Interestingly enough, I couldn't reproduce error on Windows running node.js with the same project.

[calzoneman]

I am having a similar problem on node 10.0 (I'm using connect and socket.io). I don't get an out of memory exception, but I do experience 100% CPU usage. I don't have a test case, but my server application will reliably begin eating 100% CPU at some point, usually within 48 hours of launching it. I used the tick module to profile my application and the most heavy function was *onread net.js:464 (the line number has since changed, but observing the file history this particular function was not changed). My suspicion is that a client socket is ending up in a bad state and causing an infinite loop.

I am also using CentOS 6.

Relevant portion of log:

 [Bottom up (heavy) profile]:
  Note: percentage shows a share of a particular caller in the total
  amount of its parent calls.
  Callers occupying less than 2.0% are not shown.

   ticks parent  name
  6861788   82.1%  /lib64/libc-2.12.so

  669966    8.0%  /usr/local/bin/node
  56824    8.5%    LazyCompile: *EventEmitter.emit events.js:53
  56817  100.0%      LazyCompile: *onread net.js:464
  15685    2.3%    LazyCompile: ADD native runtime.js:163
  15682  100.0%      LazyCompile: *onread net.js:464

EDIT: Searching around, it appears a few other people are having the same nondeterministic 100% CPU usage issue. If there's any more information I can provide, or if my issue is distinct and should be opened anew, please let me know.

[isaacs]

The fact that onread in net.js was a large portion of your time is actually pretty normal.

In order to make any progress on this, I need to reproduce it. Obviously a standalone node-only test is best, but even a sporadically failing test case that uses Express would be better than nothing. If you are seeing this on smartos, then a core dump would also be useful.

If page is reloaded twice quickly or several requests are made by clicking a button, the memory leak warning is triggered and node.js runs 100% cpu.

Have you tried on 0.10.3? There was an actual bug that got fixed.

[suprraz]

Experiencing same issue v0.10.3 on centos 6.0. Does not occur 0.9.4. Here's the resource usage from top:

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
11066 root 20 0 831m 768m 6228 R 97.1 44.9 72:19.81 node

Process has not crashed, but server takes minutes to respond. Same behavior as calzoneman's description above.

[calzoneman]

@razvan346 interesting, I'll try downgrading to 0.9.4 and seeing if that eliminates the problem. Which modules are you using and what kind of application is it? Perhaps if we can determine similarities we can narrow down a test case.

[calzoneman]

Nope, still getting CPU usage issue on 0.9.4

[suprraz]

I have isolated this issue locally to serving static files via connect.static('public'). More specifically this was only reproducible serving index.html. Turn off javascript to prevent other requests and hold ctrl-r or command-r to refresh rapidly until cpu goes to 99%.

Also, @calzoneman you are right. It occurs in 0.9.4 as well.

[suprraz]

Reproducible in the same fashion described above using the buffet static serving module (https://github.com/carlos8f/node-buffet). This appears to be a node/centos issue rather than a module issue.

[isaacs]

If you have a server that's serving stuff, and you're hitting it as fast as possible, it's expected that it'll use all the available CPU to do its work. It's doing work. That's what CPUs are for.

Are you getting it to print "Possible eventemitter leak detected", or not?

Just because 2 modules perform badly, that doesn't mean that Node has a bug. It could well be that both modules are just broken, perhaps in similar ways.

Using https://github.com/isaacs/st, I can't get this to happen.

[suprraz]

To clarify, once done hitting the server as fast as possible, the cpu usage will REMAIN at 100% until the node process is restarted.

[suprraz]

I just re-tested with the buffet module- the CPU remains at 100%, however it does not print Emitter Leak errors. Also, the server remains responsive, where with express static would not.
EDIT: Memory footprint does keep growing (observed to 15x original), indicating a leak

[calzoneman]

As far as I know, the issue on my end is not triggered by someone mashing refresh. It's possible that @razvan346's test is simply triggering the problem much faster because of the high rate of requests, and it's also possible that the issues are distinct.

I have confirmed that my issue (100% CPU usage indefinitely after being triggered by an undetermined stimulus) occurs in node 0.9.4 and 0.10.x, but does not occur in 0.8.23. I'm using express to serve static files and socket.io for websocket communication, and using the same version of these modules across node versions (previously I was using connect for file serving, same results across versions).

I will try to test my software with isaacs/st for completeness

[RonaldPannekoek]

On CentOS 6.4 I have the same problem.
To create the problem you have to cancel a download from a client-browser (open a page with a big video and close the tab before it is finished downloading).
Then the request ._socketEnd-event starts looping.
This is how I stop it on my test-machine in Express:

app.configure(function(){
    app.use(function (req, res, next) {
    res.socket.on('_socketEnd',function() {
      var s = this;
      console.log('res.socket.on _socketEnd'); //See the problem
      if (s) s.destroy(); //Stop the loop
    });
    next();
    });
});

On my LAN it was hard to trigger the loop, because the download went to quick.
On-line on a production machine it was easier to trigger the loop with a video.
On my production machines I went back to node 0.8.23, because I don’t know if my solution has side effects.

Hope this helps solving the real problem.

[calzoneman]

Interesting, I had a suspicion that it was being caused by a dirty disconnect. I've been using node 0.8.23 as well, and it's working fine for now but obviously I'd much rather have the option of using an up-to-date version.

It's a bit late where I am, but tomorrow I'll try testing this on other distros to see if it's specific to CentOS or if it's a node/module problem.

I don't think this is the same issue as the one in the original post of this thread; perhaps one of us should open a new Issue for this?

[calzoneman]

I have confirmed the issue on both CentOS 6 and Debian 6, both using node 0.10.4.

Here is a full test case based on @RonaldPannekoek's given code that demonstrates the issue:

var fs = require('fs');
var app = require('express')();
app.configure(function() {
  app.use(function(req, res, next) {
    res.socket.on('_socketEnd', function() {
      var s = this;
      console.log('res.socket.on _socketEnd');
      // if(s) s.destroy(); // Uncomment to try his workaround
    });
    next();
  });
});

app.get('/', function(req, res) {
  // Or some other huge file
  fs.readFile('100mb.test', function(err, data) {
    res.send(data+"");
  });
});

app.listen(8080);

Testing: Navigate to http://servername:8080, and close the tab before the file is fully loaded
Expected behaviour: 'res.socket.on _socketEnd' is printed once, and the socket is destroyed
Actual behaviour: 'res.socket.on _socketEnd' is printed repeatedly and CPU usage is locked at 100%

[mtyaka]

This seems to be related to #5298.

[IfnotFr]

With putting net.js to debug i can have this writing indefinitely even where all connections looks to be closed : https://gist.github.com/AnaelFavre/5274181

It seems that net.js tries to read a badly closed connection witch is now destroyed ?
NET: 1485 onread EOF "undefined undefined NaN"

[isaacs]

That onread EOF "undefined undefined NaN" is normal. It's just telling you that it got the EOF signal, and that the chunk, offset, and length are all unset (which is normal in the EOF case).

[IfnotFr]

I understand. Sorry for useless intervention !

[isaacs]

I tested with this script which uses node only:

var fs = require('fs');
var http = require('http');

var b = new Buffer(100 * 1024 * 1024);
b.fill('x');
fs.writeFileSync('100mb.test', b);
b = null;

var server = http.createServer(function(req, res) {
  res.socket.on('_socketEnd', function() {

    var s = this;
    console.log('res.socket.on _socketEnd');

    // if(s) s.destroy(); // Uncomment to try his workaround
  });

  fs.readFile('100mb.test', function(err, data) {
    res.end(data + '');
  });
});

server.listen(8080);

Of course, it's dog slow, because it's not optimizing anything, and it's converting from a buffer to a string unnecessarily, and probably ought to be streaming to use less memory. But it finishes just fine, doesn't go into any kind of infinite loop, and seems to behave as expected.

[v0lkan]

Getting the error with PubNub especially under poor network conditions.

First I suspected it was due to event loop being congested (I was programming a microcontroller, so blocking the event loop is easier than a beefier web server) — though no matter how slow I open the sockets, yield things with setTimeout/setImmediate etc; I still got the error.

node v0.10.32 on Tessel TM-00-04 (firmware updated on Feb 9th 2015)

I don’t have diagnostic info to share right now; I will post when I have some.

[Kurtz1993]

Still happening in 0.10.36 :S

[nicholas-c]

Still getting this on mysql pool connection - 0.10.28 (Different server than above) - CentOS

"connection.on('error', function (err) {"

(node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.
Trace
at PoolConnection.EventEmitter.addListener (events.js:160:15)
at .../nodejs/nodeServer/app/rest-api.js:47:15
at Ping.onPing [as _callback] (.../app/node_modules/mysql/lib/Pool.js:94:5)
at Ping.Sequence.end (...app/node_modules/mysql/lib/protocol/sequences/Sequence.js:96:24)
at Ping.Sequence.OkPacket (.../app/node_modules/mysql/lib/protocol/sequences/Sequence.js:105:8)
at Protocol._parsePacket (.../app/node_modules/mysql/lib/protocol/Protocol.js:271:23)
at Parser.write (/.../app/node_modules/mysql/lib/protocol/Parser.js:77:12)
at Protocol.write (...app/node_modules/mysql/lib/protocol/Protocol.js:39:16)
at Socket.<anonymous> (/.../app/node_modules/mysql/lib/Connection.js:82:28)
at Socket.EventEmitter.emit (events.js:95:17)

[mz3]

I'm getting this error using Grunt with Node v0.12.2.

[sam-github]

I think this should be closed. Its expected to get this warning when adding more than 11 event listeners to an emitter. You can get all the listeners from the EE and investigate what listeners were added, but unless there is evidence that node itself is leaking emitters, this is expected behaviour. Gather that evidence and reopen when if it can be found.

[jasnell]

@sam-github 👍

[amir-rahnama]

I am still getting this error with Node 4.2.1 using JSDom 7.1.1 when trying to scrape a page every second:

(node) warning: possible EventEmitter memory leak detected. 11 error listeners added. Use emitter.setMaxListeners() to increase limit.
Trace
    at Socket.addListener (events.js:239:17)
    at Socket.Readable.on (_stream_readable.js:665:33)
    at Object.done (/Users/ara/dev/iteam/data-mining/streamers/scrape/inloggedcars.js:24:22)
    at /Users/ara/dev/iteam/data-mining/streamers/node_modules/jsdom/lib/jsdom.js:271:18
    at doNTCallback0 (node.js:417:9)
    at process._tickCallback (node.js:346:13)

[rizvanhaider]

I got the same issue on this code with strongloop(loopback)

module.exports = function (app) {
    var dataSourceDS1 = app.dataSources.DS1;
    var dataSourceDS2 = app.dataSources.DS2;
    var ReLocationTbl = dataSourceDS1.models["ReLocationTbl"]
    var MmLocationTbl = dataSourceDS2.models["MmLocationTbl"]
    MmLocationTbl.find(function (err, data) {
            if (!err) {
                console.log(data.length)
               data.forEach(function(location){
                   console.log(location)
                     ReLocationTbl.create(
                        location,
                        function (err, obj) {
                            if (!err) {
                                console.log("Success posting "+ location)
                            } else
                                console.log("Failed  posting "+ location)
                            console.log(err)
                        })
               }) 

            }
        })
}

[aldegoeij]

+1

[calzoneman]

This has probably been mentioned multiple times in this thread, but because nobody bothers to read it, here's a comment from literally 5 comments above mine:

I think this should be closed. Its expected to get this warning when adding more than 11 event listeners to an emitter. You can get all the listeners from the EE and investigate what listeners were added, but unless there is evidence that node itself is leaking emitters, this is expected behaviour. Gather that evidence and reopen when if it can be found.

[tuwid]

having the same issue with request (that uses the http core module )

[ghost]

Please read:
angular-fullstack/generator-angular-fullstack#1136 (comment)

[blaskovicz]

I agree with @calzoneman, the fix in my case was that I had to call:
someEmitterObj.removeListener('eventName', func);.

doc reference