simple http example fails in v0.10.2 #5179

Closed
ry opened this Issue Mar 30, 2013 · 20 comments

8 participants

@ry
ry commented Mar 30, 2013

v0.10.2

i'm getting a lot of warnings like this

(node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.

when i copy the http example from the homepage into a file and run ab against it.

% ab -t 30 -c 100  http://127.0.0.1:1337/
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Send request failed!
apr_socket_recv: Connection reset by peer (54)
Total of 1 requests completed
-54- ryan@yyy:~% cat /tmp/x.js
var http = require('http');
http.createServer(function (req, res) {
    res.writeHead(200, {'Content-Type': 'text/plain'});
      res.end('Hello World\n');
}).listen(1337, '127.0.0.1');
console.log('Server running at http://127.0.0.1:1337/');

Note that ab reports "Total of 1 requests completed".

@ijohn

Just tried to do what you did. I got different result:

$ ab -t 30 -c 100  http://127.0.0.1:1337/
This is ApacheBench, Version 2.3 <$Revision: 655654 $>
Copyright 1996 Adam Twiss, Zeus Technology Ltd, http://www.zeustech.net/
Licensed to The Apache Software Foundation, http://www.apache.org/

Benchmarking 127.0.0.1 (be patient)
Completed 5000 requests
Completed 10000 requests
Completed 15000 requests
apr_poll: The timeout specified has expired (70007)
Total of 16469 requests completed

The node console doesn't write anything else beside:

$ node x
Server running at http://127.0.0.1:1337/

I tested on Mac OS X 10.8.3, using node-v0.10.2.pkg from nodejs.org home page

@Sironfoot

ijohn: It's timing out after 15/16k requests because you're quickly exceeding the maximum available ports in OSX (around 16k I think), see https://groups.google.com/forum/?fromgroups=#!topic/nodejs/399xJfWw-OI

ry: I'm not getting the "EventEmitter memory leak detected..." error on OSX, just ijohn's above error. But I do get this intermittently on a default install express app. I'm running node 0.10.2 on OSX 10.8.3

Update: I've tried running "siege" against the homepage node example, and a default express app, e.g.

siege --benchmark http://127.0.0.1:1337/

...and I'm not getting any EventEmitter memory leak errors at all.

@indutny
Node.js Foundation member

Just found this issue. Basically, its apache benchmark bug, because osx version that is installed by default is basically broken.

However, we're aware of this leak and will eventually fix it. Though, its low priority thing for us, because this leak is pretty harmless - eventemitter dies with connection and connection dies right after this leak.

@indutny indutny was assigned Mar 31, 2013
@isaacs

@indutny @ry Can you run with --throw-deprecation and post the stack trace output?

@isaacs

@indutny Yeah, even if it's harmless, it means something is doing the wrong thing. I can't seem to reproduce with the ab I have, though.

@bnoordhuis
Node.js Foundation member

I've not been able to reproduce it reliably but the ab that Apple ships with 10.8.2 sometimes gets stuck in a loop where it keeps sending requests over the same connection without waiting for a reply. The ab from upstream doesn't have that issue.

@ry
ry commented Mar 31, 2013

oops i didn't post whole output from that warning:

(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 ServerResponse.OutgoingMessage._writeRaw (http.js:530:14)
    at ServerResponse.OutgoingMessage._send (http.js:489:15)
    at ServerResponse.OutgoingMessage.write (http.js:803:16)
    at ServerResponse.OutgoingMessage.end (http.js:944:16)
    at Server.<anonymous> (/private/tmp/x.js:4:11)
    at Server.EventEmitter.emit (events.js:98:17)
    at HTTPParser.parser.onIncoming (http.js:2022:12)
    at HTTPParser.parserOnHeadersComplete [as onHeadersComplete] (http.js:119:23)

on my MBP v10.8.2 this is reproducible about half of the time.

@ijohn

I am a node.js newbie. I don't know whether what I'm going to inform has anything to do with this thread. Sorry if it doesn't.

I am currently working with node-amqp and I can always reproduce the possible EventEmitter memory leak warning message.

$ npm install amqp
$ cat x.js
var amqp = require('amqp');
var connection = amqp.createConnection({host: 'localhost'});
connection.on('ready', function () {
  connection.queue('theQueue', {'durable': true, 'autoDelete': false});
});
connection.on('error', function () {
  console.log('Got error');
});
$ node x
Got error
Got error
Got error
Got error
Got error
Got error
Got error
Got error
(node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.
Trace
    at Connection.EventEmitter.addListener (events.js:160:15)
    at Connection.EventEmitter.once (events.js:179:8)
    at Connection.connect (/Users/john/Projects/Temp/trynode/node_modules/amqp/amqp.js:1069:8)
    at Connection.reconnect (/Users/john/Projects/Temp/trynode/node_modules/amqp/amqp.js:1038:8)
    at null._onTimeout (/Users/john/Projects/Temp/trynode/node_modules/amqp/amqp.js:876:16)
    at Timer.listOnTimeout [as ontimeout] (timers.js:110:15)
Got error
(node) warning: possible EventEmitter memory leak detected. 11 listeners added. Use emitter.setMaxListeners() to increase limit.
Trace
    at Connection.EventEmitter.addListener (events.js:160:15)
    at Connection.connect (/Users/john/Projects/Temp/trynode/node_modules/amqp/amqp.js:1068:8)
    at Connection.reconnect (/Users/john/Projects/Temp/trynode/node_modules/amqp/amqp.js:1038:8)
    at null._onTimeout (/Users/john/Projects/Temp/trynode/node_modules/amqp/amqp.js:876:16)
    at Timer.listOnTimeout [as ontimeout] (timers.js:110:15)
Got error
Got error
^C%

I deliberately didn't start RabbitMQ before running x.js. This is on Mac OS X 10.8.3 and node 0.10.2.

@indutny
Node.js Foundation member

That's leak in amqp module, not in node.js

@ijohn ijohn referenced this issue in postwait/node-amqp Apr 1, 2013
Open

Possible Memory leaks #167

@isaacs isaacs was assigned Apr 1, 2013
@isaacs

@ry Thanks. Yes, this is indeed harmless, but also stupid and annoying. It's a bit of code to work around a v0.8 bug, and at least according to the comment I wrote next to it, it shouldn't be necessary in 0.10.

Patch today.

@isaacs

@ry Can you try applying isaacs@deb1dc2?

@ry
ry commented Apr 2, 2013

that seems to fix it

@ry
ry commented Apr 2, 2013

(i get pretty sad numbers from ab though... ~1800 req/sec .... why?)

@bnoordhuis
Node.js Foundation member

Abstractions cost. :-/

@isaacs

@bnoordhuis Can you explain what you mean by that?

@bnoordhuis
Node.js Foundation member

That I can do 60k req/s with the raw bindings and only 20k req/s with the http library. The http library is easier to work with but that ease of use comes at a price.

@isaacs

Sure, but dropping from 7000 to 1800 here in @ry's case is clearly not because of any recent change to Node. ab is misbehaving.

@isaacs isaacs added a commit to isaacs/node that referenced this issue Apr 2, 2013
@isaacs isaacs http: Remove legacy ECONNRESET workaround code
Fix #5179
feceb26
@dsn
dsn commented Apr 3, 2013

Using the test provided by @ry, here are the results I get using Node v0.8.22 and v0.10.2.
In both cases I do not see the EventEmitter Warnings, although I do see a drop in performance using 0.10.2

AB Version: 2.3 <$Revision: 655654 $>

ab -t 30 -c 100 http://localhost:1337/

Node: 0.8.22

Concurrency Level:      100
Time taken for tests:   12.539 seconds
Complete requests:      50000
Failed requests:        0
Requests per second:    3987.57 [#/sec] (mean)

Node: 0.10.2

Concurrency Level:      100
Time taken for tests:   16.788 seconds
Complete requests:      50000
Failed requests:        0
Requests per second:    2978.39 [#/sec] (mean)
@isaacs

Closed by 88686aa

@isaacs isaacs closed this Apr 3, 2013
@chiragsanghvi

Hi,

I'm getting warnings like this

(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 ServerResponse.OutgoingMessage._writeRaw (http.js:530:14)
at ServerResponse.OutgoingMessage._send (http.js:489:15)
at ServerResponse.OutgoingMessage.write (http.js:803:16)
at ServerResponse.OutgoingMessage.end (http.js:944:16)
at Server. (/Users/chiragsanghvi/CustomCode/libraries/cluster.js:20:9)
at Server.EventEmitter.emit (events.js:98:17)
at HTTPParser.parser.onIncoming (http.js:2022:12)

== running cluster code from node website , tried setting maxlisteners ,but not working.

var cluster = require('cluster');
var http = require('http');
var numCPUs = require('os').cpus().length;

process.setMaxListeners(0);
if (cluster.isMaster) {
// Fork workers.
for (var i = 0; i < numCPUs; i++) {
cluster.fork();
}

cluster.on('exit', function(worker, code, signal) {
console.log('worker ' + worker.process.pid + ' died');
});
} else {
// Workers can share any TCP connection
// In this case its a HTTP server
var server = http.createServer(function(req, res) {
res.writeHead(200);
res.end("hello world\n");
});
server.setMaxListeners(0);
server.listen(8000);
}

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment