Block new incoming requests once close has been called #886

delvedor · 2018-04-15T20:22:40Z

Currently, if a user calls fastify.close and the server is under a heavy load, the server will not close until there is an open TCP connection, so every new request will execute the entire request lifecycle.

With this change once fastify.close is invoked, Fastify will automatically start to respond with a 503 error, closing every new connection as soon as possible.

There are not sensible changes in the benchmarks.

Checklist

run npm run test and npm run benchmark
tests and/or benchmarks are included
documentation is changed or added
commit message and code follows Code of conduct

allevo · 2018-04-15T21:23:58Z

I'm -1 with this feature (from my point of view this is a breaking behaviour change).

Anyway I'm +1 if the close method signature will be close(force, callback) with default set to false.

delvedor · 2018-04-15T21:33:37Z

I'm -1 with this feature (from my point of view this is a breaking behaviour change).

Actually, it can be interpreted as a bugfix.
Close is a LIFO queue of onClose handlers, once a user calls close it will activate that queue, closing database connections for example. This will lead to many errors inside the various route handlers, which is not very nice.
With this change, we are actually protecting the server from all that kind of errors.

mcollina

The example with inject is wrong. Can you use a http request with an agent with keep-alive?

@allevo, this is necessary for send() to actually work. If there is a keepalive connection, the connection is never severed, making a graceful disconnect not possible.

nwoltman · 2018-04-15T21:46:21Z

Close is a LIFO queue of onClose handlers

Really? I assumed it was FIFO. So in this code:

fastify.onClose(async () => {
  // This is called second
})

fastify.onClose(async () => {
  // And this is called first
})

?

allevo · 2018-04-15T22:01:26Z

I don't understand. I expect that the HTTP server is closed before any other dependencies. Is this the currently behaviour ?

delvedor · 2018-04-15T22:40:54Z

Really? I assumed it was FIFO.

@nwoltman yes. The reason is because the last plugin you have have registered should be the first you must close.

nwoltman · 2018-04-16T06:23:58Z

@delvedor In that case, what about registering this onClose handler last so that connections are closed before running the other onClose handlers?

fastify/fastify.js

Lines 112 to 118 in 5fefda9

    
           fastify.onClose((instance, done) => { 
        
             if (listening) { 
        
               instance.server.close(done) 
        
             } else { 
        
               done(null) 
        
             } 
        
           })

delvedor · 2018-04-16T07:35:17Z

@nwoltman done. But the problem persist, because of the keep alive connections as @mcollina pointed out.

nwoltman · 2018-04-16T16:43:43Z

@delvedor You're right, I forgot about the keep-alive connections. Would it help to include a Connection: close header in the 503 response?

delvedor · 2018-04-16T20:38:08Z

@nwoltman it should be the default, but it will not hurt ;)

nwoltman · 2018-04-16T20:53:26Z

close is the default for HTTP/1.0 requests, but modern browsers use HTTP/1.1 where the default is to use a keep-alive connection.

The changes LGTM, although I think @mcollina has a good point about testing with something that uses keep-alive connections instead of .inject().

delvedor · 2018-04-16T20:56:56Z

I'm trying to write a test with keep alive, but I'm having some trouble to get it working.
Any suggestion?
https://gist.github.com/delvedor/558a1569d7db6e2c0c9e3870eb96fd33

mcollina · 2018-04-17T10:05:45Z

@delvedor you should verify it's reusing the same socket. I don't think it is, as you are not resuming the response. Also, add a maxSocket: 1 option to the agent.

delvedor · 2018-04-17T13:20:28Z

It seems that AppVeyor is failing for a test that is not present in this branch 🤔

StarpTech · 2018-04-17T13:31:58Z

fastify.js

+    if (closing === true) {
+      res.writeHead(503, {
+        'Content-Type': 'application/json',
+        'Content-Length': '80',


Could you calculate it based on the payload as with 404 ?

That 80 is the length of the json response ;)

I know. It's better to write payload.length

It is the payload length.
We can do the same at the line you have pointed pointed out, since the payload will be always the same.

StarpTech · 2018-04-17T13:58:10Z

@delvedor I'm trying to reproduce it on my machine.

StarpTech · 2018-04-17T14:04:53Z

@delvedor can't reproduce it on local Node 6.13.1 ~~I think the timeouts aren't solid try to increase them.~~ retrigger the build.

delvedor · 2018-04-17T14:07:04Z

@StarpTech one of the two AppVeyor logs shows
error is not logged because promise was fulfilled with undefined but response was sent before promise resolution not ok Request timed out.
Which is not a test we are running in this branch. Do you know why?

StarpTech · 2018-04-17T14:19:08Z

@delvedor no idea. Try to rebuild.

delvedor · 2018-04-17T14:26:20Z

I can't, @mcollina should do it.

mcollina · 2018-04-17T14:28:08Z

done.

mcollina · 2018-04-17T14:36:28Z

You'll need to increaase that timeout: https://ci.appveyor.com/project/mcollina/fastify/build/job/x2ml3eliuojq3au2#L41.

StarpTech · 2018-04-18T13:41:16Z

@delvedor performance of what? The request / response shouldn't be effected.

delvedor · 2018-04-18T14:01:24Z

@StarpTech for every new connection you should update a Set and every time that a connection will be closed you should again update that Set. This is overhead that I don't want to pay unless I don't have to.

StarpTech · 2018-04-18T14:16:01Z

@delvedor you are worried about to maintain a set? What's the alternative to close all pending connections? From my understanding, the problem is that server.close does not clean up the connections in the way we want?

delvedor · 2018-04-18T14:49:54Z

I'm worried about the cost of maintaining a Set.

Regarding server.close, this is the behavior (documentation):

Stops the server from accepting new connections and keeps existing connections. This function is asynchronous, the server is finally closed when all connections are ended

StarpTech · 2018-04-18T18:32:26Z

@delvedor https://github.com/hunterloftis/stoppable This looks promising refer to design and performance.

StarpTech · 2018-04-18T18:44:30Z

There is also an interesting thread about it nodejs/node#2642 Node.js does not close existing, idle connections. We should support it.

delvedor · 2018-04-18T19:41:55Z

@StarpTech I know, I've already read that issue before open this pr.
The problem is the same, you are keeping a Map, calling .set and .delete very often.
That is pure overhead. I'm looking for a solution with the least overhead.

What I don't understand it's why the test are failing in travis but not in my local machine.

StarpTech · 2018-04-18T19:43:44Z

They are failing really randomly. Sometimes it works sometimes not. Try to run the single test in isolation.

delvedor · 2018-04-18T21:28:55Z

@mcollina can you check if the usage of autocannon is correct?

mcollina

Can you move the autocannon tests to a new file?

delvedor · 2018-04-18T21:50:45Z

Done, I've also added another check.
What is the difference?

allevo · 2018-04-19T06:12:09Z

test/close-pipelining.test.js

+      t.strictEqual(codes.shift(), statusCode)
+    })
+
+    instance.on('done', () => t.pass())


Can you use t.done? It is more clear

allevo · 2018-04-19T06:14:18Z

fastify.js

-    } else {
-      done(null)
-    }
+  app.once('preReady', () => {


Maybe overwriting avvio ready method fits better here. Or not?

Can you rephrase?

Putting the onClose handler inside preReady event doesn't ensure that the callback is invoked before any others. It does only if the preReady callbacks are fired in FIFO.

We use

https://github.com/mcollina/avvio/blob/a957201b0b33facf06687a5ba8e52c82a46b1302/boot.js#L13

and creating ready method inside fastify.

The new method forces the add onClose handler as the last, so the first one to be invoked.

It does only if the preReady callbacks are fired in FIFO.

They are, it is an event emitter.

We can't use ready inside Fastify, because ready will start the boot sequence.

allevo

LGTM

nwoltman

LGTM (once tests are passing)

mcollina

LGTM with green CI

mcollina · 2018-05-25T08:39:38Z

Green CI! 🎉

github-actions · 2022-02-17T00:13:37Z

This pull request has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.

delvedor added 3 commits April 15, 2018 22:20

Block new incoming requests once close has been called

be0cebb

Updated test

1b1bb25

Updated docs

244fb12

delvedor added enhancement semver-minor Issue or PR that should land as semver minor labels Apr 15, 2018

delvedor requested a review from a team April 15, 2018 20:22

mcollina reviewed Apr 15, 2018

View reviewed changes

Register server on close as the first on close hook

02e6ed9

Added connection header

f7392f6

StarpTech reviewed Apr 17, 2018

View reviewed changes

delvedor force-pushed the block-requests-on-close branch from 4a40e67 to 30428f3 Compare April 18, 2018 19:46

Added keep alive test on close

930292a

delvedor force-pushed the block-requests-on-close branch from 30428f3 to 930292a Compare April 18, 2018 19:57

mcollina reviewed Apr 18, 2018

View reviewed changes

Use autocannon to test connection pipelining on close

affc212

delvedor force-pushed the block-requests-on-close branch from 89d7374 to affc212 Compare April 18, 2018 21:49

allevo reviewed Apr 19, 2018

View reviewed changes

allevo approved these changes Apr 21, 2018

View reviewed changes

nwoltman approved these changes Apr 21, 2018

View reviewed changes

delvedor added 3 commits May 22, 2018 09:56

WIP: request timeout

2bfa557

Merge branch 'master' into block-requests-on-close

8574b2d

Destroy the request once close has been called

e0e5491

mcollina approved these changes May 24, 2018

View reviewed changes

Updated test

0e8a992

delvedor merged commit cbd08af into master May 25, 2018

delvedor deleted the block-requests-on-close branch May 25, 2018 08:46

allevo mentioned this pull request Jun 21, 2019

Avoid return 503 after closing fastify #1714

Closed

github-actions bot locked as resolved and limited conversation to collaborators Feb 17, 2022

Uh oh!

Block new incoming requests once close has been called #886

Block new incoming requests once close has been called #886

Uh oh!

Conversation

delvedor commented Apr 15, 2018

Checklist

Uh oh!

allevo commented Apr 15, 2018

Uh oh!

delvedor commented Apr 15, 2018

Uh oh!

mcollina left a comment

Choose a reason for hiding this comment

Uh oh!

nwoltman commented Apr 15, 2018

Uh oh!

allevo commented Apr 15, 2018

Uh oh!

delvedor commented Apr 15, 2018

Uh oh!

nwoltman commented Apr 16, 2018

Uh oh!

delvedor commented Apr 16, 2018

Uh oh!

nwoltman commented Apr 16, 2018

Uh oh!

delvedor commented Apr 16, 2018

Uh oh!

nwoltman commented Apr 16, 2018

Uh oh!

delvedor commented Apr 16, 2018

Uh oh!

mcollina commented Apr 17, 2018

Uh oh!

delvedor commented Apr 17, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

StarpTech commented Apr 17, 2018

Uh oh!

StarpTech commented Apr 17, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

delvedor commented Apr 17, 2018

Uh oh!

StarpTech commented Apr 17, 2018

Uh oh!

delvedor commented Apr 17, 2018

Uh oh!

mcollina commented Apr 17, 2018

Uh oh!

mcollina commented Apr 17, 2018

Uh oh!

StarpTech commented Apr 18, 2018

Uh oh!

delvedor commented Apr 18, 2018

Uh oh!

StarpTech commented Apr 18, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

delvedor commented Apr 18, 2018

Uh oh!

StarpTech commented Apr 18, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

StarpTech commented Apr 18, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

delvedor commented Apr 18, 2018

Uh oh!

StarpTech commented Apr 18, 2018

Uh oh!

delvedor commented Apr 18, 2018

StarpTech commented Apr 17, 2018 •

edited

Loading

StarpTech commented Apr 18, 2018 •

edited

Loading

StarpTech commented Apr 18, 2018 •

edited

Loading

StarpTech commented Apr 18, 2018 •

edited

Loading

nwoltman left a comment •

edited

Loading