nodejs / node-v0.x-archive

Moved to https://github.com/nodejs/node
34.43k stars 7.31k forks source link

simple http example fails in v0.10.2 #5179

Closed ry closed 11 years ago

ry commented 11 years ago

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 commented 11 years ago

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 commented 11 years ago

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 commented 11 years ago

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.

isaacs commented 11 years ago

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

isaacs commented 11 years ago

@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 commented 11 years ago

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 commented 11 years ago

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 commented 11 years ago

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 commented 11 years ago

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

isaacs commented 11 years ago

@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 commented 11 years ago

@ry Can you try applying https://github.com/isaacs/node/commit/deb1dc279d49463e13af44feed45c79ae0f379f9?

ry commented 11 years ago

that seems to fix it

ry commented 11 years ago

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

bnoordhuis commented 11 years ago

Abstractions cost. :-/

isaacs commented 11 years ago

@bnoordhuis Can you explain what you mean by that?

bnoordhuis commented 11 years ago

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 commented 11 years ago

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.

dsn commented 11 years ago

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 commented 11 years ago

Closed by 88686aa

chiragsanghvi commented 11 years ago

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); }