Repository navigation
Socket setTimeout behaviour not working as expected for HTTP requests #5899
Description
Summary
timeout events are fired on sockets assigned to an HTTP request even when there is activity (data being written) within the timeout period. This is unexpected and not explicitly documented.
This did not used to be the case, it used to work like a normal net socket, with the timeout being essentially "reset" on any activity. The behaviour changed after this commit 607bbd3 without any obvious doc changes.
Full background
A TCP (net) socket has a setTimeout method which sets the socket to emit a timeout event after a certain number of ms of inactivity. This currently works correctly on all tested versions. An example is below:
var net = require('net');
var server = net.createServer(function (socket) {
socket.setTimeout(200, socket.destroy); // Setting to less than 100 will cause timeout
socket.pipe(process.stdout);
});
server.listen(function () {
var client = net.connect(server.address().port, function () {
var interval = setInterval(function () {
client.write('a');
}, 100);
setTimeout(function () {
clearInterval(interval);
client.end();
server.close();
}, 1000);
});
});There’s also a setTimeout method available on a HTTP request which proxies the setTimeout call through to the underlying TCP socket. So I expected it to work the same. But it does not, it will timeout even when data is being written actively to the socket.
var http = require('http');
var server = http.createServer(function (req, res) {
req.setTimeout(200); // this will timeout even though data is being written
req.pipe(process.stdout);
req.on('end', function () { res.end() });
});
server.listen(function () {
var address = server.address();
var req = http.request({
port: address.port,
method: 'POST'
});
var interval = setInterval(function () {
req.write('a');
}, 100);
setTimeout(function () {
clearInterval(interval);
req.end();
server.close();
}, 1000);
});It was an issue posted at hapijs/hapi#3099 that led me to this digging. I used the script above to git bisect the Node core repo back to the commit where the behaviour changed 607bbd3 which is part of PR #2355.
Conclusion
I think this is either a bug or If the new behaviour is intended, a documentation update is probably needed to explicitly state that the timeout on an http socket works differently than a regular net socket.
- Version: 607bbd3 - master
- Platform: Darwin 15.3.0 Darwin Kernel Version 15.3.0: Thu Dec 10 18:40:58 PST 2015; root:xnu-3248.30.4~1/RELEASE_X86_64 x86_64
- Subsystem: net, http
Activity
silverwind commentedon Mar 30, 2016
Dupe of #3319 maybe?edit: closed the other issue as this one has more detail.
silverwind commentedon Mar 30, 2016
@indutny
indutny commentedon Mar 30, 2016
cc @nodejs/http
alanstott commentedon Apr 17, 2016
+1
indutny commentedon Apr 19, 2016
Confirmed, caused by stream consumption indeed. Working on a fix, thanks!
http: unref socket timer on parser execute
indutny commentedon Apr 19, 2016
Fix #6286
http: unref socket timer on parser execute
http: unref socket timer on parser execute
http: unref socket timer on parser execute
http: unref socket timer on parser execute
baolinCloud commentedon May 16, 2016
I met the same issue with node-v0.10.36, should I upgrade the node to solve this problem? Any other ideas?
cjihrig commentedon May 16, 2016
Yes. This likely won't make it back to the 0.10 release line.
thomas-riccardi commentedon May 17, 2016
@baolinCloud node-v0.10 doesn't include the initial commit 607bbd3 that introduced the regression. lib/http.js hasn't changed on things related to timeout since before this regression commit: https://github.com/nodejs/node/commits/v0.10/lib/http.js
And we only encountered the issue when starting using node v4.
So I think this bug is not present in node v0.10.
thomas-riccardi commentedon May 17, 2016
nodejs v4.4.4 was released after this fix landed on master, but didn't include this fix.
It was released in v5.11.0 though (although with no explicit comment explaining that setTimeout was broken...), and v6.0.0.
When will this be released in v4.x ?
This is a severe regression for all users of setTimeout.
jasnell commentedon May 17, 2016
v4.4.4 was intentionally limited to a smaller set of security related fixes. I imagine this can hit in v4.4.5. /cc @thealphanerd
MylesBorins commentedon May 17, 2016
I just push this change to
v4.x-stagingand it will be included inv4.4.5Expect an rc later today and a release next week
http: unref socket timer on parser execute
http: unref socket timer on parser execute
baolinCloud commentedon May 18, 2016
@triccardi-systran My test code is simple:
var http = require('http');
server = http.createServer(function (request, response) {
setTimeout(function() {
response.writeHead(200, {'Content-Type': 'text/plain'});
response.end('Hello World\n');
}, 200);
request.socket.setTimeout(500);
request.socket.removeAllListeners('timeout');
request.socket.once('timeout', function () {
response.writeHead(200, {'content-type': 'text/html'});
response.end('hello world');
console.log('timeout');
});
}).listen(1337, '127.0.0.1');
When I use postman to get from http://127.0.0.1:1337 , I get the response of 'Hello World'. But also log 'timeout'. My node version is 0.10.36. Any thing is wrong with my code? I just want to set timeout to less than 2min.
mtharrison commentedon May 18, 2016
@baolinCloud I think that's expected behaviour. You responded and ended the first request in the 200ms timeout, then the socket (still connected because of Keep-Alive) times out.
If you just want to change the timeout on the server to less than 2 min use
server.setTimeout():baolinCloud commentedon May 18, 2016
@mtharrison I want to catch the timeout event and response a specified message.
For example, if time out , log the event and response 'hello'. Otherwise, response 'HELLO'.
And I don not want to log timeout if not timeout.
In fact I always get the timeout log whether timeout or not.
Any ideas ?
matthiasg commentedon Oct 23, 2020
This seems to happen again in node 14. Really bad behavior. Uploads stop at about 1m with ECONNRESET
kanongil commentedon Oct 23, 2020
@matthiasg You should open a new issue with details.