http server.close() is taking about 2 mins to close

[Kiran Ravuri]

Hi All,

I am testing cluster in node, and i had a question regarding that which  i posted

@ http://stackoverflow.com/questions/31934358/nodejs-worker-disconnect-not-working-as-expected

This is the followup question to that, cos i found the similar behavior in this test . 

SERVER :

var http=require("http"),
  server = null;

server =http.createServer(function (request, response) {
  request.on("end", function(){
    console.log("reqest end " + new Date());
  });
  request.on("data", function(data) {
    console.log("I am here");
    console.log(data.toString("utf8"));
  });
  response.writeHead(200, {'Content-Type': 'text/plain'});
  response.end('Hello World\n');
}).listen(3000);

server.on('request', function(sock) {
  console.log('Got Request ' + new Date());
});

setTimeout(function(){
  console.log('SERVER: calling server.close ' + new Date() );
  server.close(function() {
    console.log('SERVER: has closed ' + new Date() )
  });
}, 5000);

LOG:

> node app/http_server_test.js
Got Request Wed Aug 12 2015 20:09:21 GMT+0530 (IST)
reqest end Wed Aug 12 2015 20:09:21 GMT+0530 (IST)
SERVER: calling server.close Wed Aug 12 2015 20:09:23 GMT+0530 (IST)
SERVER: has closed Wed Aug 12 2015 20:11:17 GMT+0530 (IST)

My question is why the server is taking that much time( about 2 mins) to close even though there are no pending requests in the queue??

Thanks in advance.

BRs

Kiran 

[Maximilian Hill]

Maybe the socket is wariting for FIN of some connrctions.

Max

--
Job board: http://jobs.nodejs.org/
New group rules: https://gist.github.com/othiym23/9886289#file-moderation-policy-md
Old group rules: https://github.com/joyent/node/wiki/Mailing-List-Posting-Guidelines
---
You received this message because you are subscribed to the Google Groups "nodejs" group.
To unsubscribe from this group and stop receiving emails from it, send an email to nodejs+un...@googlegroups.com.
To post to this group, send email to nod...@googlegroups.com.
To view this discussion on the web visit https://groups.google.com/d/msgid/nodejs/f2f4e2e0-0954-485e-a496-c0e9ba285cfa%40googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Kiran Ravuri]

There are no pending requests. As you can see in the log there is only one request and server replied to that and i got 'end' event for that.

With out any requests if i give server.close() is working properly. Even if it servers one request it is taking long to close. You can just copy paste that code in your test environment and send a request to localhost:3000 to observe the behaviour.

[Kiran Ravuri]

UPDATED code with 'finish' event

var http=require("http"),
  server = null;

server = http.createServer(function (request, response) {
  request.on("end", function(){
    console.log("server: reqest end " + new Date());
  });
  response.on('finish', function () {
      console.log('server: response finish ' + new Date());
  });
  response.on('close', function () {
      console.log('server: response close ' + new Date() );
  });

  response.writeHead(200, {'Content-Type': 'text/plain'});
  response.end('Hello World\n');
}).listen(3000);
server.on('request', function(sock) {

  console.log('server: got request ' + new Date());
});
setTimeout(function(){
  console.log('server: calling server.close ' + new Date() );
  server.close(function() {
    console.log('server: has closed ' + new Date() )
  });
}, 10000);

LOG:

> node app/http_server_test.js 

server: got request Thu Aug 13 2015 10:45:36 GMT+0530 (IST)

server: response finish Thu Aug 13 2015 10:45:36 GMT+0530 (IST)

server: reqest end Thu Aug 13 2015 10:45:36 GMT+0530 (IST)

server: calling server.close Thu Aug 13 2015 10:45:41 GMT+0530 (IST)

server: has closed Thu Aug 13 2015 10:47:32 GMT+0530 (IST)

[Maximilian Hill]

I can't reproduce it.

File with modification (read line instead of timeout):

var http=require("http"),
  server = null;

var readline = require("readline");

var rl = readline.createInterface({
  input: process.stdin,
  output: process.stdout
});

server = http.createServer(function (request, response) {
  request.on("end", function(){
    console.log("server: reqest end " + new Date());
  });
  response.on('finish', function () {
      console.log('server: response finish ' + new Date());
  });
  response.on('close', function () {
      console.log('server: response close ' + new Date() );
  });
  response.writeHead(200, {'Content-Type': 'text/plain'});
  response.end('Hello World\n');
}).listen(3000);
server.on('request', function(sock) {
  console.log('server: got request ' + new Date());
});

rl.on('line', function(){

  console.log('server: calling server.close ' + new Date() );
  server.close(function() {

    console.log('server: has closed ' + new Date() );
    /* process.exit(); */
  });
});

My output:

$ node test.js
server: response finish Thu Aug 13 2015 17:17:52 GMT+0200 (CEST)
server: got request Thu Aug 13 2015 17:17:52 GMT+0200 (CEST)
server: reqest end Thu Aug 13 2015 17:17:52 GMT+0200 (CEST)
server: response finish Thu Aug 13 2015 17:18:04 GMT+0200 (CEST)
server: got request Thu Aug 13 2015 17:18:04 GMT+0200 (CEST)
server: reqest end Thu Aug 13 2015 17:18:04 GMT+0200 (CEST)

server: calling server.close Thu Aug 13 2015 17:18:16 GMT+0200 (CEST)
server: has closed Thu Aug 13 2015 17:18:16 GMT+0200 (CEST)

By using process.exit() node stops directly after stopping the server.

My test envoironment is an VPS with CentOS 7 and node from epel
$ node --version
v0.10.36

I tested with requests from wget http://127.0.0.1:3000/

M

To view this discussion on the web visit https://groups.google.com/d/msgid/nodejs/6b772d61-2339-4a0f-96e7-ffbf22447766%40googlegroups.com.

[Kiran Ravuri]

Hi Thanks for the reply

Nothing has changed for me, I ran your code and i got 

server: got request Fri Aug 14 2015 10:32:11 GMT+0530 (IST)
server: response finish Fri Aug 14 2015 10:32:11 GMT+0530 (IST)
server: reqest end Fri Aug 14 2015 10:32:11 GMT+0530 (IST)


server: calling server.close Fri Aug 14 2015 10:32:16 GMT+0530 (IST)
server: has closed Fri Aug 14 2015 10:34:06 GMT+0530 (IST)

I am using ubuntu 12.04 with v0.12.2. Let me try with v0.10.36.

BRs,

Kiran

[Kiran Ravuri]

Hi 

I tried even with your node version. v0.10.36

Still I got same issue.

[kyolo...@gmail.com]

Hello,

it seems server can not close immediately after setTimeout(5 sec). Maybe server is waiting for HTTP pipeline close and it can close after HTTP close

在 2015年8月13日星期四 UTC+8上午3:39:40，Kiran Ravuri写道：