Race condition between socket timeout and new client requests

[pmalouin]

Environment = Node 0.10.38
I've been debugging a nasty ECONNRESET error occuring when the keepAliveTimeout is very close to the interval between two http requests.

Setting the NODE_DEBUG variable to "http,agentkeepalive", I could see the following interactions:

[...]
CLIENT socket onTimeout
CLIENT socket onTimeout
HTTP: write ret = false
HTTP: outgoing message end.
CLIENT socket onClose
removeSocket 127.0.0.1:9499:: destroyed: true
CLIENT socket onClose
removeSocket 127.0.0.1:9499:: destroyed: true
HTTP: HTTP socket close

And then my code catches the following error:

[Error: socket hang up] code: 'ECONNRESET'
Error: socket hang up
    at createHangUpError (http.js:1473:15)
    at Socket.socketCloseListener (http.js:1523:23)
    at Socket.emit (events.js:117:20)
    at TCP.close (net.js:466:12)

What's wrong with this sequence of events is that the onTimeout method is called but a new http request is added very shortly after. In the meantime, the net.Socket.destroy() call effectively destroys the socket in the middle of the request.

I will prepare a pull request for a change to onTimeout() that removes the socket from self.freeSockets immediately instead of waiting for the 'close' event. This way no new request will be channeled through this socket during its destruction.

Unfortunately, I'm not able to provide a simple test case because I don't know how to artificially expand the delay between the 'timeout' and 'close' events.

[pmalouin]

I was able to reproduce the problem with this small script:

var Agent = require('agentkeepalive');
var http = require('http');

var _keepaliveAgent = new Agent({
    maxSockets: 1,
    maxFreeSockets: 1,
    keepAliveTimeout: 1000
});

var options = {
    hostname: 'www.google.com',
    port: 80,
    path: '/',
    method: 'GET',
    agent : _keepaliveAgent
};

var getRequest = function() {
    var req =  http.request(options, function(res) {
        res.on('data', function(chunk) {
            console.log('BODY: ' + chunk);
        });
        res.on('end', function() {
            console.log('END REQ');
        });
    });
    req.on('error', function(e) {
        console.log('problem with request: ', e);
    });
    return req;
};

var req = getRequest();
// Get a reference to the socket.
req.on('socket', function(sock) {
    // Listen to timeout and send another request immediately.
    sock.on('timeout', function() {
        getRequest().end();
    });
});
req.end();

setTimeout(function() {
    // Just keep the process hanging because listening to 'timeout' is not enough to keep the process spinning.
}, 2500);

The first http request succeeds, the second fails with ECONNRESET.

[fengmk2]

e6a83a5

[pmalouin]

Thanks, I updated and it's all good for me!