Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

In node V 9.0.0, HTTP Client Agent is leaking when reusing a socket in HTTP Request #16716

Closed
CesarLRosa opened this issue Nov 3, 2017 · 7 comments
Labels
http Issues or PRs related to the http subsystem.

Comments

@CesarLRosa
Copy link

  • Version: 9.0.0
  • Platform: x86_64 GNU/Linux
  • Subsystem: core http

This is the first issue that I open. I apologize in advanced if I did something wrong...

When making HTTP requests with an HTTP Agent to make the reuse of the connected socket, I got the following warning:

  • (node:27613) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connect listeners added. Use emitter.setMaxListeners() to increase limit

I look at the source, and I discovered that this block of code is causing the leak:
https://github.com/nodejs/node/blob/master/lib/_http_client.js#L731-L733

In node 8.9.0, there isn't the * sock.once('connect', function() { block, only the line * sock.setTimeout(msecs, emitTimeout);. I change those lines to ** block, only the line * sock.setTimeout(msecs, emitTimeout); in node 9.0.0 and everything work just fine.

Here is the code that can evidence the problem:

"use strict";

const util = require('util');

const http = require("http");

const agentOptions = new Object();
agentOptions.keepAlive = true;
agentOptions.keepAliveMsecs = 15000;
agentOptions.maxSockets = 32;
agentOptions.maxFreeSockets = 32;

const httpAgent = new http.Agent(agentOptions);


const requestObj = new Object();
requestObj.host = '127.0.0.1';
requestObj.port = 55001;
requestObj.method = 'GET';
requestObj.path = '/';
  

requestObj.agent = httpAgent;


var counter = 0;



process.on('warning', function(emmiter) {
  
  console.error(`process.on warning ${util.inspect(emmiter)}`);
  
});



const doRequest = function(requestObj) {
  
  const req = http.request(requestObj, httpOk);
  
  req.on('error', httpError);
    
  req.setTimeout(15000, httpTimeout);
  
  req.end();
  
}


const httpTimeout = function(err) {
  
  console.error(`httpError():err=${err}`);
  
}

const httpError = function(err) {
  
  console.error(`httpError():err=${err}`);
  
}


const onResponseError = function(err) {
  
  console.error(`onResponseError():err=${err}`);
  
}

const onResponseEnd = function() {
  
  if (counter != 20000) {
    
    doRequest(requestObj);
    
    if ((counter % 1000) == 0) {
      console.log(`onResponseEnd():Make ${counter} requests ok.`);
    }
    
  } else {
    console.log(`onResponseEnd():Done.`);
  }
  
}


const onResponseData = function(data) {
  
}


const httpOk = function(response) {
  
  response.on('data', onResponseData);
  response.on('end', onResponseEnd);
  response.on('error', onResponseError);
  
  if (response.statusCode == 200) {
    
    counter++;
    
  } else {
    console.log(`httpOk():Got Unexpected response=${response.statusCode}`);
  }
  
}


doRequest(requestObj);

Here is an server code that can be used with the client above:

"use strict";


const onRequest = function(request, response) {
  response.on('error', function(e) {console.log(`Error ${e} ${e.stack}`)});
  response.end();
  
}

const port = 55001;
const http = require("http");

const server = http.createServer(onRequest);

server.listen(port);
console.log(`Server is listening on port '${port}'`);

If the socket in the HTTP Agent is reused for thousands of requests without be closed, it can cause the node process to stop because there is no more memory to allocate.

Here is the output of the client code in node 8.9.0:
./node-v8.9.0/bin/node --use_strict main-httpAgentClient.js
onResponseEnd():Make 1000 requests ok.
onResponseEnd():Make 2000 requests ok.
onResponseEnd():Make 3000 requests ok.
onResponseEnd():Make 4000 requests ok.
onResponseEnd():Make 5000 requests ok.
onResponseEnd():Make 6000 requests ok.
onResponseEnd():Make 7000 requests ok.
onResponseEnd():Make 8000 requests ok.
onResponseEnd():Make 9000 requests ok.
onResponseEnd():Make 10000 requests ok.
onResponseEnd():Make 11000 requests ok.
onResponseEnd():Make 12000 requests ok.
onResponseEnd():Make 13000 requests ok.
onResponseEnd():Make 14000 requests ok.
onResponseEnd():Make 15000 requests ok.
onResponseEnd():Make 16000 requests ok.
onResponseEnd():Make 17000 requests ok.
onResponseEnd():Make 18000 requests ok.
onResponseEnd():Make 19000 requests ok.
onResponseEnd():Done.

Here is the output of the client code in node 9.0.0:
/node-v9.0.0-ORIG/bin/node --use_strict main-httpAgentClient.js
(node:27930) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connect listeners added. Use emitter.setMaxListeners() to increase limit
process.on warning { MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connect listeners added. Use emitter.setMaxListeners() to increase limit
at _addListener (events.js:289:19)
at Socket.addListener (events.js:306:10)
at Socket.Readable.on (_stream_readable.js:775:35)
at Socket.once (events.js:349:8)
at ClientRequest. (_http_client.js:731:10)
at Object.onceWrapper (events.js:324:30)
at emitOne (events.js:130:20)
at ClientRequest.emit (events.js:221:7)
at tickOnSocket (_http_client.js:656:7)
at onSocketNT (_http_client.js:672:5)
name: 'MaxListenersExceededWarning',
emitter:
Socket {
connecting: false,
_hadError: false,
_handle:
TCP {
reading: true,
owner: [Circular],
onread: [Function: onread],
onconnection: null,
writeQueueSize: 0 },
_parent: null,
_host: null,
_readableState:
ReadableState {
objectMode: false,
highWaterMark: 16384,
buffer: [BufferList],
length: 0,
pipes: null,
pipesCount: 0,
flowing: true,
ended: false,
endEmitted: false,
reading: true,
sync: false,
needReadable: true,
emittedReadable: false,
readableListening: false,
resumeScheduled: false,
destroyed: false,
defaultEncoding: 'utf8',
awaitDrain: 0,
readingMore: false,
decoder: null,
encoding: null },
readable: true,
domain: null,
_events:
{ end: [Array],
finish: [Function: onSocketFinish],
_socketEnd: [Function: onSocketEnd],
free: [Function: onFree],
close: [Array],
agentRemove: [Function: onRemove],
connect: [Array],
drain: [Function: ondrain],
error: [Function: socketErrorListener],
data: [Function: socketOnData] },
_eventsCount: 10,
_maxListeners: undefined,
_writableState:
WritableState {
objectMode: false,
highWaterMark: 16384,
finalCalled: false,
needDrain: false,
ending: false,
ended: false,
finished: false,
destroyed: false,
decodeStrings: false,
defaultEncoding: 'utf8',
length: 0,
writing: false,
corked: 0,
sync: false,
bufferProcessing: false,
onwrite: [Function: bound onwrite],
writecb: null,
writelen: 0,
bufferedRequest: null,
lastBufferedRequest: null,
pendingcb: 0,
prefinished: false,
errorEmitted: false,
bufferedRequestCount: 0,
corkedRequestsFree: [Object] },
writable: true,
allowHalfOpen: false,
_bytesDispatched: 780,
_sockname: null,
_pendingData: null,
_pendingEncoding: '',
server: null,
_server: null,
parser:
HTTPParser {
'0': [Function: parserOnHeaders],
'1': [Function: parserOnHeadersComplete],
'2': [Function: parserOnBody],
'3': [Function: parserOnMessageComplete],
'4': null,
_headers: [],
_url: '',
_consumed: false,
socket: [Circular],
incoming: null,
outgoing: [ClientRequest],
maxHeaderPairs: 2000,
onIncoming: [Function: parserOnIncomingClient] },
_httpMessage:
ClientRequest {
domain: null,
_events: [Object],
_eventsCount: 3,
_maxListeners: undefined,
output: [],
outputEncodings: [],
outputCallbacks: [],
outputSize: 0,
writable: true,
_last: true,
upgrading: false,
chunkedEncoding: false,
shouldKeepAlive: true,
useChunkedEncodingByDefault: false,
sendDate: false,
_removedConnection: false,
_removedContLen: false,
_removedTE: false,
_contentLength: 0,
_hasBody: true,
_trailer: '',
finished: true,
_headerSent: true,
socket: [Circular],
connection: [Circular],
_header: 'GET / HTTP/1.1\r\nHost: 127.0.0.1:55001\r\nConnection: keep-alive\r\n\r\n',
_onPendingData: [Function: noopPendingOutput],
agent: [Agent],
socketPath: undefined,
timeout: undefined,
method: 'GET',
path: '/',
_ended: false,
res: null,
aborted: undefined,
timeoutCb: [Function: emitTimeout],
upgradeOrConnect: false,
parser: [HTTPParser],
maxHeadersCount: null,
[Symbol(outHeadersKey)]: [Object] },
read: [Function],
_consuming: true,
_idleTimeout: -1,
_idleNext: null,
_idlePrev: null,
_idleStart: 60,
_destroyed: false,
[Symbol(asyncId)]: 278,
[Symbol(bytesRead)]: 0,
[Symbol(asyncId)]: 14,
[Symbol(triggerAsyncId)]: 9 },
type: 'connect',
count: 11 }
(node:27930) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connect listeners added. Use emitter.setMaxListeners() to increase limit
process.on warning { MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 connect listeners added. Use emitter.setMaxListeners() to increase limit
at _addListener (events.js:289:19)
at Socket.addListener (events.js:306:10)
at Socket.Readable.on (_stream_readable.js:775:35)
at Socket.once (events.js:349:8)
at ClientRequest. (_http_client.js:731:10)
at Object.onceWrapper (events.js:324:30)
at emitOne (events.js:130:20)
at ClientRequest.emit (events.js:221:7)
at tickOnSocket (_http_client.js:656:7)
at onSocketNT (_http_client.js:672:5)
name: 'MaxListenersExceededWarning',
emitter:
Socket {
connecting: false,
_hadError: false,
_handle:
TCP {
reading: true,
owner: [Circular],
onread: [Function: onread],
onconnection: null,
writeQueueSize: 0 },
_parent: null,
_host: null,
_readableState:
ReadableState {
objectMode: false,
highWaterMark: 16384,
buffer: [BufferList],
length: 0,
pipes: null,
pipesCount: 0,
flowing: true,
ended: false,
endEmitted: false,
reading: true,
sync: false,
needReadable: true,
emittedReadable: false,
readableListening: false,
resumeScheduled: false,
destroyed: false,
defaultEncoding: 'utf8',
awaitDrain: 0,
readingMore: false,
decoder: null,
encoding: null },
readable: true,
domain: null,
_events:
{ end: [Array],
finish: [Function: onSocketFinish],
_socketEnd: [Function: onSocketEnd],
free: [Function: onFree],
close: [Array],
agentRemove: [Function: onRemove],
connect: [Array],
drain: [Function: ondrain],
error: [Function: socketErrorListener],
data: [Function: socketOnData] },
_eventsCount: 10,
_maxListeners: undefined,
_writableState:
WritableState {
objectMode: false,
highWaterMark: 16384,
finalCalled: false,
needDrain: false,
ending: false,
ended: false,
finished: false,
destroyed: false,
decodeStrings: false,
defaultEncoding: 'utf8',
length: 0,
writing: false,
corked: 0,
sync: false,
bufferProcessing: false,
onwrite: [Function: bound onwrite],
writecb: null,
writelen: 0,
bufferedRequest: null,
lastBufferedRequest: null,
pendingcb: 0,
prefinished: false,
errorEmitted: false,
bufferedRequestCount: 0,
corkedRequestsFree: [Object] },
writable: true,
allowHalfOpen: false,
_bytesDispatched: 780,
_sockname: null,
_pendingData: null,
_pendingEncoding: '',
server: null,
_server: null,
parser:
HTTPParser {
'0': [Function: parserOnHeaders],
'1': [Function: parserOnHeadersComplete],
'2': [Function: parserOnBody],
'3': [Function: parserOnMessageComplete],
'4': null,
_headers: [],
_url: '',
_consumed: false,
socket: [Circular],
incoming: null,
outgoing: [ClientRequest],
maxHeaderPairs: 2000,
onIncoming: [Function: parserOnIncomingClient] },
_httpMessage:
ClientRequest {
domain: null,
_events: [Object],
_eventsCount: 3,
_maxListeners: undefined,
output: [],
outputEncodings: [],
outputCallbacks: [],
outputSize: 0,
writable: true,
_last: true,
upgrading: false,
chunkedEncoding: false,
shouldKeepAlive: true,
useChunkedEncodingByDefault: false,
sendDate: false,
_removedConnection: false,
_removedContLen: false,
_removedTE: false,
_contentLength: 0,
_hasBody: true,
_trailer: '',
finished: true,
_headerSent: true,
socket: [Circular],
connection: [Circular],
_header: 'GET / HTTP/1.1\r\nHost: 127.0.0.1:55001\r\nConnection: keep-alive\r\n\r\n',
_onPendingData: [Function: noopPendingOutput],
agent: [Agent],
socketPath: undefined,
timeout: undefined,
method: 'GET',
path: '/',
_ended: false,
res: null,
aborted: undefined,
timeoutCb: [Function: emitTimeout],
upgradeOrConnect: false,
parser: [HTTPParser],
maxHeadersCount: null,
[Symbol(outHeadersKey)]: [Object] },
read: [Function],
_consuming: true,
_idleTimeout: -1,
_idleNext: null,
_idlePrev: null,
_idleStart: 63,
_destroyed: false,
[Symbol(asyncId)]: 293,
[Symbol(bytesRead)]: 0,
[Symbol(asyncId)]: 29,
[Symbol(triggerAsyncId)]: 26 },
type: 'connect',
count: 11 }
onResponseEnd():Make 1000 requests ok.
onResponseEnd():Make 2000 requests ok.
onResponseEnd():Make 3000 requests ok.
onResponseEnd():Make 4000 requests ok.
onResponseEnd():Make 5000 requests ok.
onResponseEnd():Make 6000 requests ok.
onResponseEnd():Make 7000 requests ok.
onResponseEnd():Make 8000 requests ok.
onResponseEnd():Make 9000 requests ok.
onResponseEnd():Make 10000 requests ok.
onResponseEnd():Make 11000 requests ok.
onResponseEnd():Make 12000 requests ok.
onResponseEnd():Make 13000 requests ok.
onResponseEnd():Make 14000 requests ok.
onResponseEnd():Make 15000 requests ok.
onResponseEnd():Make 16000 requests ok.
onResponseEnd():Make 17000 requests ok.
onResponseEnd():Make 18000 requests ok.
onResponseEnd():Make 19000 requests ok.
onResponseEnd():Done.

Here is the output of the client code in node 9.0.0 with the fix:
./node-v9.0.0-NEW/bin/node --use_strict main-httpAgentClient.js
onResponseEnd():Make 1000 requests ok.
onResponseEnd():Make 2000 requests ok.
onResponseEnd():Make 3000 requests ok.
onResponseEnd():Make 4000 requests ok.
onResponseEnd():Make 5000 requests ok.
onResponseEnd():Make 6000 requests ok.
onResponseEnd():Make 7000 requests ok.
onResponseEnd():Make 8000 requests ok.
onResponseEnd():Make 9000 requests ok.
onResponseEnd():Make 10000 requests ok.
onResponseEnd():Make 11000 requests ok.
onResponseEnd():Make 12000 requests ok.
onResponseEnd():Make 13000 requests ok.
onResponseEnd():Make 14000 requests ok.
onResponseEnd():Make 15000 requests ok.
onResponseEnd():Make 16000 requests ok.
onResponseEnd():Make 17000 requests ok.
onResponseEnd():Make 18000 requests ok.
onResponseEnd():Make 19000 requests ok.
onResponseEnd():Done.

Thanks.

@mscdex mscdex added http Issues or PRs related to the http subsystem. v9.x labels Nov 3, 2017
@maclover7
Copy link
Contributor

@CesarLRosa Can you confirm that this did not occur in previous versions of Node, and first appeared in v9.0.0?

@apapirovski
Copy link
Member

This looks like a result of #8895 — ping @lpinca @nodejs/http

@lpinca
Copy link
Member

lpinca commented Nov 3, 2017

It makes sense, the socket is reused and still connected so we only keep adding more listeners as the 'connect' event is not emitted.

It should be easily fixable by checking if the socket is connected and use the 'connect' listener only when it isn't.

@lpinca
Copy link
Member

lpinca commented Nov 3, 2017

I'll work on a fix and add a regression test as soon as I can.

@lpinca
Copy link
Member

lpinca commented Nov 3, 2017

@CesarLRosa can you confirm that this patch fixes the issue?

@CesarLRosa
Copy link
Author

@lpinca
Yes, your patch fix the issue! I run the test that I posted on this issue, and several other tests to check the HTTP Agent behavior, and everything is working just fine!

Thanks a lot for the fast fixing!

@lpinca
Copy link
Member

lpinca commented Nov 4, 2017

Let's keep this open until the patch lands in master.

@lpinca lpinca reopened this Nov 4, 2017
lpinca added a commit to lpinca/node that referenced this issue Nov 6, 2017
Fixes a bug that prevented `ClientRequest.prototype.setTimeout()` from
working properly when the socket was reused for multiple requests.

Fixes: nodejs#16716
Refs: nodejs#8895
@lpinca lpinca closed this as completed in f60c692 Nov 6, 2017
cjihrig pushed a commit to cjihrig/node that referenced this issue Nov 6, 2017
Fixes a bug that prevented `ClientRequest.prototype.setTimeout()` from
working properly when the socket was reused for multiple requests.

Fixes: nodejs#16716
Refs: nodejs#8895
PR-URL: nodejs#16725
Reviewed-By: Rich Trott <rtrott@gmail.com>
Reviewed-By: James M Snell <jasnell@gmail.com>
Reviewed-By: Colin Ihrig <cjihrig@gmail.com>
Reviewed-By: Benjamin Gruenbaum <benjamingr@gmail.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
http Issues or PRs related to the http subsystem.
Projects
None yet
Development

Successfully merging a pull request may close this issue.

5 participants